From f512628af2cced65a6be469561a6e78c8f150aad Mon Sep 17 00:00:00 2001 From: sebres Date: Tue, 6 Sep 2016 20:15:45 +0200 Subject: [PATCH 01/27] make with_foreground_server_thread decorator to test several client/server commands --- fail2ban/tests/fail2banclienttestcase.py | 96 ++++++++++++++---------- 1 file changed, 55 insertions(+), 41 deletions(-) diff --git a/fail2ban/tests/fail2banclienttestcase.py b/fail2ban/tests/fail2banclienttestcase.py index ed2d3c46..6d4691fe 100644 --- a/fail2ban/tests/fail2banclienttestcase.py +++ b/fail2ban/tests/fail2banclienttestcase.py @@ -41,6 +41,7 @@ from ..client.fail2banclient import exec_command_line as _exec_client, VisualWai from ..client.fail2banserver import Fail2banServer, exec_command_line as _exec_server from .. import protocol from ..server import server +from ..server.mytime import MyTime from ..server.utils import Utils from .utils import LogCaptureTestCase, with_tmpdir, shutil, logging @@ -303,47 +304,60 @@ class Fail2banClientServerBase(LogCaptureTestCase): phase['end'] = True logSys.debug("end of test worker") - @with_tmpdir - def testStartForeground(self, tmp): - # intended to be ran only in subclasses - th = None - phase = dict() - try: - # started directly here, so prevent overwrite test cases logger with "INHERITED" - startparams = _start_params(tmp, logtarget="INHERITED") - # because foreground block execution - start it in thread: - th = Thread( - name="_TestCaseWorker", - target=self._testStartForeground, - args=(tmp, startparams, phase) - ) - th.daemon = True - th.start() - try: - # wait for start thread: - Utils.wait_for(lambda: phase.get('start', None) is not None, MAX_WAITTIME) - self.assertTrue(phase.get('start', None)) - # wait for server (socket and ready): - self._wait_for_srv(tmp, True, startparams=startparams) - self.pruneLog() - # several commands to server: - self.execSuccess(startparams, "ping") - self.execFailed(startparams, "~~unknown~cmd~failed~~") - self.execSuccess(startparams, "echo", "TEST-ECHO") - finally: - self.pruneLog() - # stop: - self.execSuccess(startparams, "stop") - # wait for end: - Utils.wait_for(lambda: phase.get('end', None) is not None, MAX_WAITTIME) - self.assertTrue(phase.get('end', None)) - self.assertLogged("Shutdown successful", "Exiting Fail2ban") - finally: - if th: - # we start client/server directly in current process (new thread), - # so don't kill (same process) - if success, just wait for end of worker: - if phase.get('end', None): - th.join() + def with_foreground_server_thread(startextra={}): + """Helper to decorate tests uses foreground server (as thread), started directly in test-cases + + To be used only in subclasses + """ + def _deco_wrapper(f): + @with_tmpdir + @wraps(f) + def wrapper(self, tmp, *args, **kwargs): + th = None + phase = dict() + try: + # started directly here, so prevent overwrite test cases logger with "INHERITED" + startparams = _start_params(tmp, logtarget="INHERITED", **startextra) + # because foreground block execution - start it in thread: + th = Thread( + name="_TestCaseWorker", + target=self._testStartForeground, + args=(tmp, startparams, phase) + ) + th.daemon = True + th.start() + try: + # wait for start thread: + Utils.wait_for(lambda: phase.get('start', None) is not None, MAX_WAITTIME) + self.assertTrue(phase.get('start', None)) + # wait for server (socket and ready): + self._wait_for_srv(tmp, True, startparams=startparams) + self.pruneLog() + # several commands to server in body of decorated function: + return f(self, tmp, startparams, *args, **kwargs) + finally: + self.pruneLog() + # stop: + self.execSuccess(startparams, "stop") + # wait for end: + Utils.wait_for(lambda: phase.get('end', None) is not None, MAX_WAITTIME) + self.assertTrue(phase.get('end', None)) + self.assertLogged("Shutdown successful", "Exiting Fail2ban") + finally: + if th: + # we start client/server directly in current process (new thread), + # so don't kill (same process) - if success, just wait for end of worker: + if phase.get('end', None): + th.join() + return wrapper + return _deco_wrapper + + @with_foreground_server_thread() + def testStartForeground(self, tmp, startparams): + # several commands to server: + self.execSuccess(startparams, "ping") + self.execFailed(startparams, "~~unknown~cmd~failed~~") + self.execSuccess(startparams, "echo", "TEST-ECHO") class Fail2banClientTest(Fail2banClientServerBase): From b12a3acb06fed4f240e1cea20f4b07f913edf221 Mon Sep 17 00:00:00 2001 From: sebres Date: Tue, 6 Sep 2016 23:54:19 +0200 Subject: [PATCH 02/27] temp commit: reload not ready... --- fail2ban/client/beautifier.py | 2 +- fail2ban/client/fail2banclient.py | 43 ++- fail2ban/protocol.py | 7 +- fail2ban/server/actions.py | 29 +- fail2ban/server/filter.py | 97 ++++-- fail2ban/server/filterpoll.py | 30 +- fail2ban/server/filtersystemd.py | 10 +- fail2ban/server/jail.py | 3 +- fail2ban/server/jails.py | 11 +- fail2ban/server/server.py | 134 ++++++-- fail2ban/server/transmitter.py | 36 +- fail2ban/tests/fail2banclienttestcase.py | 403 +++++++++++++++++++---- fail2ban/tests/servertestcase.py | 4 +- fail2ban/tests/utils.py | 8 +- 14 files changed, 646 insertions(+), 171 deletions(-) diff --git a/fail2ban/client/beautifier.py b/fail2ban/client/beautifier.py index bd803a6a..2d2c0caf 100644 --- a/fail2ban/client/beautifier.py +++ b/fail2ban/client/beautifier.py @@ -46,7 +46,7 @@ class Beautifier: return self.__inputCmd def beautify(self, response): - logSys.debug( + logSys.log(5, "Beautify " + repr(response) + " with " + repr(self.__inputCmd)) inC = self.__inputCmd msg = response diff --git a/fail2ban/client/fail2banclient.py b/fail2ban/client/fail2banclient.py index 788906aa..9bc1525e 100755 --- a/fail2ban/client/fail2banclient.py +++ b/fail2ban/client/fail2banclient.py @@ -91,7 +91,7 @@ class Fail2banClient(Fail2banCmdLine, Thread): client = CSocket(self._conf["socket"]) ret = client.send(c) if ret[0] == 0: - logSys.debug("OK : %r", ret[1]) + logSys.log(5, "OK : %r", ret[1]) if showRet or c[0] == 'echo': output(beautifier.beautify(ret[1])) else: @@ -104,7 +104,7 @@ class Fail2banClient(Fail2banCmdLine, Thread): if showRet or c != ["ping"]: self.__logSocketError() else: - logSys.debug(" -- ping failed -- %r", e) + logSys.log(5, " -- ping failed -- %r", e) return False except Exception as e: # pragma: no cover if showRet or self._conf["verbose"] > 1: @@ -226,11 +226,11 @@ class Fail2banClient(Fail2banCmdLine, Thread): # prepare: read config, check configuration is valid, etc.: if phase is not None: phase['start'] = True - logSys.debug(' client phase %s', phase) + logSys.log(5, ' client phase %s', phase) stream = self.__prepareStartServer() if phase is not None: phase['ready'] = phase['start'] = (True if stream else False) - logSys.debug(' client phase %s', phase) + logSys.log(5, ' client phase %s', phase) if not stream: return False # configure server with config stream: @@ -246,6 +246,10 @@ class Fail2banClient(Fail2banCmdLine, Thread): # @param cmd the command line def __processCommand(self, cmd): + # wrap tuple to list (because could be modified here): + if not isinstance(cmd, list): + cmd = list(cmd) + # process: if len(cmd) == 1 and cmd[0] == "start": ret = self.__startServer(self._conf["background"]) @@ -253,8 +257,12 @@ class Fail2banClient(Fail2banCmdLine, Thread): return False return ret - elif len(cmd) == 1 and cmd[0] == "restart": - + elif len(cmd) >= 1 and cmd[0] == "restart": + # if restart jail - re-operate via "reload --restart ...": + if len(cmd) > 1: + cmd[0:1] = ["reload", "--restart"] + return self.__processCommand(cmd) + # restart server: if self._conf.get("interactive", False): output(' ## stop ... ') self.__processCommand(['stop']) @@ -273,9 +281,21 @@ class Fail2banClient(Fail2banCmdLine, Thread): return self.__processCommand(['start']) elif len(cmd) >= 1 and cmd[0] == "reload": + # reload options: + opts = [] + while len(cmd) >= 2: + if cmd[1] in ('--restart', "--unban", "--if-exists"): + opts.append(cmd[1]) + del cmd[1] + else: + if len(cmd) > 2: + logSys.error("Unexpected argument(s) for reload: %r", cmd[1:]) + return False + # stop options - jail name or --all + break if self.__ping(): if len(cmd) == 1: - jail = 'all' + jail = '--all' ret, stream = self.readConfig() else: jail = cmd[1] @@ -283,9 +303,10 @@ class Fail2banClient(Fail2banCmdLine, Thread): # Do not continue if configuration is not 100% valid if not ret: return False - self.__processCmd([['stop', jail]], False) - # Configure the server - return self.__processCmd(stream, True) + if self._conf.get("interactive", False): + output(' ## reload ... ') + # Reconfigure the server + return self.__processCmd([['reload', jail, opts, stream]], True) else: logSys.error("Could not find server") return False @@ -320,7 +341,7 @@ class Fail2banClient(Fail2banCmdLine, Thread): maxtime = self._conf["timeout"] # Wait for the server to start (the server has 30 seconds to answer ping) starttime = time.time() - logSys.debug("__waitOnServer: %r", (alive, maxtime)) + logSys.log(5, "__waitOnServer: %r", (alive, maxtime)) test = lambda: os.path.exists(self._conf["socket"]) and self.__ping() with VisualWait(self._conf["verbose"]) as vis: sltime = 0.0125 / 2 diff --git a/fail2ban/protocol.py b/fail2ban/protocol.py index d671f3c3..147cd38d 100644 --- a/fail2ban/protocol.py +++ b/fail2ban/protocol.py @@ -49,8 +49,11 @@ protocol = [ ['', "BASIC", ""], ["start", "starts the server and the jails"], ["restart", "restarts the server"], -["reload", "reloads the configuration without restart"], -["reload ", "reloads the jail "], +["restart [--unban] [--if-exists] ", "restarts the jail (alias for 'reload --restart ... ')"], +["reload [--restart] [--unban] [--all]", "reloads the configuration without restarting of the server, the option '--restart' activates completely restarting of affected jails, thereby unbans IP addresses (if option '--unban' specified)"], +["reload [--restart] [--unban] [--if-exists] ", "reloads the jail , or restarts it (if option '--restart' specified)"], +["unban --all", "unbans all IP addresses (in all jails)"], +["unban ... ", "unbans (in all jails)"], ["stop", "stops all jails and terminate the server"], ["status", "gets the current status of the server"], ["ping", "tests if the server is alive"], diff --git a/fail2ban/server/actions.py b/fail2ban/server/actions.py index 050c12e6..2fab02cd 100644 --- a/fail2ban/server/actions.py +++ b/fail2ban/server/actions.py @@ -180,7 +180,7 @@ class Actions(JailThread, Mapping): def getBanTime(self): return self.__banManager.getBanTime() - def removeBannedIP(self, ip): + def removeBannedIP(self, ip=None, db=True, ifexists=False): """Removes banned IP calling actions' unban method Remove a banned IP now, rather than waiting for it to expire, @@ -188,16 +188,20 @@ class Actions(JailThread, Mapping): Parameters ---------- - ip : str or IPAddr - The IP address to unban + ip : str or IPAddr or None + The IP address to unban or all IPs if None Raises ------ ValueError If `ip` is not banned """ + # Unban all? + if ip is None: + return self.__flushBan(db) + # Single IP: # Always delete ip from database (also if currently not banned) - if self._jail.database is not None: + if db and self._jail.database is not None: self._jail.database.delBan(self._jail, ip) # Find the ticket with the IP. ticket = self.__banManager.getTicketByIP(ip) @@ -205,7 +209,11 @@ class Actions(JailThread, Mapping): # Unban the IP. self.__unBan(ticket) else: - raise ValueError("IP %s is not banned" % ip) + if ifexists: + return 0 + raise ValueError("%s is not banned" % ip) + return 1 + def run(self): """Main loop for Threading. @@ -336,14 +344,21 @@ class Actions(JailThread, Mapping): for ticket in self.__banManager.unBanList(MyTime.time()): self.__unBan(ticket) - def __flushBan(self): + def __flushBan(self, db=False): """Flush the ban list. Unban all IP address which are still in the banning list. """ logSys.debug("Flush ban list") - for ticket in self.__banManager.flushBanList(): + lst = self.__banManager.flushBanList() + for ticket in lst: + # delete ip from database also: + if db and self._jail.database is not None: + ip = str(ticket.getIP()) + self._jail.database.delBan(self._jail, ip) + # unban ip: self.__unBan(ticket) + return len(lst) def __unBan(self, ticket): """Unbans host corresponding to the ticket. diff --git a/fail2ban/server/filter.py b/fail2ban/server/filter.py index e689ff00..4c67470e 100644 --- a/fail2ban/server/filter.py +++ b/fail2ban/server/filter.py @@ -88,8 +88,9 @@ class Filter(JailThread): self.__ignoreCommand = False ## Default or preferred encoding (to decode bytes from file or journal): self.__encoding = locale.getpreferredencoding() - ## Error counter - self.__errors = 0 + ## Error counter (protected, so can be used in filter implementations) + ## if it reached 100 (at once), run-cycle will go idle + self._errors = 0 ## Ticks counter self.ticks = 0 @@ -100,6 +101,30 @@ class Filter(JailThread): def __repr__(self): return "%s(%r)" % (self.__class__.__name__, self.jail) + def clearAllParams(self): + """ Clear all lists/dicts parameters (used by reloading) + """ + self.delFailRegex() + self.delIgnoreRegex() + self.delIgnoreIP() + + def reload(self, begin=True): + """ Begin or end of reloading resp. refreshing of all parameters + """ + if begin: + self.clearAllParams() + if hasattr(self, 'getLogPaths'): + self._reload_logs = dict((k, 1) for k in self.getLogPaths()) + else: + if hasattr(self, '_reload_logs'): + dellogs = dict() + # if it was not reloaded - remove obsolete log file: + for path in self._reload_logs: + self.delLogPath(path) + delattr(self, '_reload_logs') + + + ## # Add a regular expression which matches the failure. # @@ -119,8 +144,13 @@ class Filter(JailThread): logSys.error(e) raise e - def delFailRegex(self, index): + def delFailRegex(self, index=None): try: + # clear all: + if index is None: + del self.__failRegex[:] + return + # delete by index: del self.__failRegex[index] except IndexError: logSys.error("Cannot remove regular expression. Index %d is not " @@ -152,8 +182,13 @@ class Filter(JailThread): logSys.error(e) raise e - def delIgnoreRegex(self, index): + def delIgnoreRegex(self, index=None): try: + # clear all: + if index is None: + del self.__ignoreRegex[:] + return + # delete by index: del self.__ignoreRegex[index] except IndexError: logSys.error("Cannot remove regular expression. Index %d is not " @@ -203,7 +238,7 @@ class Filter(JailThread): value = MyTime.str2seconds(value) self.__findTime = value self.failManager.setMaxTime(value) - logSys.info("Set findtime = %s" % value) + logSys.info(" findtime: %s", value) ## # Get the time needed to find a failure. @@ -232,10 +267,10 @@ class Filter(JailThread): template = DatePatternRegex(pattern) self.dateDetector = DateDetector() self.dateDetector.appendTemplate(template) - logSys.info("Date pattern set to `%r`: `%s`" % - (pattern, template.name)) - logSys.debug("Date pattern regex for %r: %s" % - (pattern, template.regex)) + logSys.info(" date pattern `%r`: `%s`", + pattern, template.name) + logSys.debug(" date pattern regex for %r: %s", + pattern, template.regex) ## # Get the date detector pattern, or Default Detectors if not changed @@ -261,7 +296,7 @@ class Filter(JailThread): def setMaxRetry(self, value): self.failManager.setMaxRetry(value) - logSys.info("Set maxRetry = %s" % value) + logSys.info(" maxRetry: %s", value) ## # Get the maximum retry value. @@ -280,7 +315,7 @@ class Filter(JailThread): if int(value) <= 0: raise ValueError("maxlines must be integer greater than zero") self.__lineBufferSize = int(value) - logSys.info("Set maxlines = %i" % self.__lineBufferSize) + logSys.info(" maxLines: %i", self.__lineBufferSize) ## # Get the maximum line buffer size. @@ -300,7 +335,7 @@ class Filter(JailThread): encoding = locale.getpreferredencoding() codecs.lookup(encoding) # Raise LookupError if invalid codec self.__encoding = encoding - logSys.info("Set jail log file encoding to %s" % encoding) + logSys.info(" encoding: %s" % encoding) return encoding ## @@ -375,11 +410,16 @@ class Filter(JailThread): ip = IPAddr(ipstr) # log and append to ignore list - logSys.debug("Add %r to ignore list (%r)", ip, ipstr) + logSys.debug(" Add %r to ignore list (%r)", ip, ipstr) self.__ignoreIpList.append(ip) - def delIgnoreIP(self, ip): - logSys.debug("Remove %r from ignore list", ip) + def delIgnoreIP(self, ip=None): + # clear all: + if ip is None: + del self.__ignoreIpList[:] + return + # delete by ip: + logSys.debug(" Remove %r from ignore list", ip) self.__ignoreIpList.remove(ip) def logIgnoreIp(self, ip, log_ignore, ignore_source="unknown source"): @@ -483,18 +523,18 @@ class Filter(JailThread): tick = FailTicket(ip, unixTime, lines, data=fail) self.failManager.addFailure(tick) # reset (halve) error counter (successfully processed line): - if self.__errors: - self.__errors //= 2 + if self._errors: + self._errors //= 2 except Exception as e: logSys.error("Failed to process line: %r, caught exception: %r", line, e, exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) # incr error counter, stop processing (going idle) after 100th error : - self.__errors += 1 + self._errors += 1 # sleep a little bit (to get around time-related errors): time.sleep(self.sleeptime) - if self.__errors >= 100: - logSys.error("Too many errors at once (%s), going idle", self.__errors) - self.__errors //= 2 + if self._errors >= 100: + logSys.error("Too many errors at once (%s), going idle", self._errors) + self._errors //= 2 self.idle = True ## @@ -657,7 +697,10 @@ class FileFilter(Filter): def addLogPath(self, path, tail=False, autoSeek=True): if path in self.__logs: - logSys.error(path + " already exists") + if hasattr(self, '_reload_logs') and path in self._reload_logs: + del self._reload_logs[path] + else: + logSys.error(path + " already exists") else: log = FileContainer(path, self.getLogEncoding(), tail) db = self.jail.database @@ -666,7 +709,7 @@ class FileFilter(Filter): if lastpos and not tail: log.setPos(lastpos) self.__logs[path] = log - logSys.info("Added logfile = %s (pos = %s, hash = %s)" , path, log.getPos(), log.getHash()) + logSys.info("Added logfile: %r (pos = %s, hash = %s)" , path, log.getPos(), log.getHash()) if autoSeek: # if default, seek to "current time" - "find time": if isinstance(autoSeek, bool): @@ -692,7 +735,7 @@ class FileFilter(Filter): db = self.jail.database if db is not None: db.updateLog(self.jail, log) - logSys.info("Removed logfile = %s" % path) + logSys.info("Removed logfile: %r" % path) self._delLogPath(path) return @@ -1055,10 +1098,14 @@ _decode_line_warn = {} class JournalFilter(Filter): # pragma: systemd no cover + def clearAllParams(self): + super(JournalFilter, self).clearAllParams() + self.delJournalMatch() + def addJournalMatch(self, match): # pragma: no cover - Base class, not used pass - def delJournalMatch(self, match): # pragma: no cover - Base class, not used + def delJournalMatch(self, match=None): # pragma: no cover - Base class, not used pass def getJournalMatch(self, match): # pragma: no cover - Base class, not used diff --git a/fail2ban/server/filterpoll.py b/fail2ban/server/filterpoll.py index 336807d4..f66be42b 100644 --- a/fail2ban/server/filterpoll.py +++ b/fail2ban/server/filterpoll.py @@ -31,7 +31,7 @@ from .failmanager import FailManagerEmpty from .filter import FileFilter from .mytime import MyTime from .utils import Utils -from ..helpers import getLogger +from ..helpers import getLogger, logging # Gets the instance of the logger. @@ -137,28 +137,34 @@ class FilterPoll(FileFilter): try: logStats = os.stat(filename) stats = logStats.st_mtime, logStats.st_ino, logStats.st_size - pstats = self.__prevStats.get(filename, ()) - self.__file404Cnt[filename] = 0 + pstats = self.__prevStats.get(filename, (0)) if logSys.getEffectiveLevel() <= 7: # we do not want to waste time on strftime etc if not necessary dt = logStats.st_mtime - pstats[0] logSys.log(7, "Checking %s for being modified. Previous/current stats: %s / %s. dt: %s", filename, pstats, stats, dt) # os.system("stat %s | grep Modify" % filename) + self.__file404Cnt[filename] = 0 if pstats == stats: return False logSys.debug("%s has been modified", filename) self.__prevStats[filename] = stats return True - except OSError as e: - logSys.error("Unable to get stat on %s because of: %s" - % (filename, e)) + except Exception as e: + # stil alive (may be deleted because multi-threaded): + if not self.getLog(filename): + logSys.warning("Log %r seems to be down: %s", filename, e) + return + # log error: + if self.__file404Cnt[filename] < 2: + logSys.error("Unable to get stat on %s because of: %s", + filename, e, + exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) + # increase file and common error counters: self.__file404Cnt[filename] += 1 - if self.__file404Cnt[filename] > 2: - logSys.warning("Too many errors. Setting the jail idle") - if self.jail is not None: - self.jail.idle = True - else: - logSys.warning("No jail is assigned to %s" % self) + self._errors += 1 + if self.__file404Cnt[filename] > 50: + logSys.warning("Too many errors. Remove file %r from monitoring process", filename) self.__file404Cnt[filename] = 0 + self.delLogPath(filename) return False diff --git a/fail2ban/server/filtersystemd.py b/fail2ban/server/filtersystemd.py index 487af793..0b6c4074 100644 --- a/fail2ban/server/filtersystemd.py +++ b/fail2ban/server/filtersystemd.py @@ -154,12 +154,16 @@ class FilterSystemd(JournalFilter): # pragma: systemd no cover # # @param match journalctl syntax matches - def delJournalMatch(self, match): - if match in self.__matches: + def delJournalMatch(self, match=None): + # clear all: + if match is None: + del self.__matches[:] + # delete by index: + elif match in self.__matches: del self.__matches[self.__matches.index(match)] - self.resetJournalMatches() else: raise ValueError("Match not found") + self.resetJournalMatches() logSys.info("Removed journal match for: %r" % " ".join(match)) ## diff --git a/fail2ban/server/jail.py b/fail2ban/server/jail.py index 92f8190e..a5dc1119 100644 --- a/fail2ban/server/jail.py +++ b/fail2ban/server/jail.py @@ -79,6 +79,7 @@ class Jail(object): logSys.info("Creating new jail '%s'" % self.name) if backend is not None: self._setBackend(backend) + self.backend = backend def __repr__(self): return "%s(%r)" % (self.__class__.__name__, self.name) @@ -220,7 +221,7 @@ class Jail(object): jail=self, bantime=self.actions.getBanTime()): if not self.filter.inIgnoreIPList(ticket.getIP(), log_ignore=True): self.__queue.put(ticket) - logSys.info("Jail '%s' started" % self.name) + logSys.info("Jail %r started", self.name) def stop(self): """Stop the jail, by stopping filter and actions threads. diff --git a/fail2ban/server/jails.py b/fail2ban/server/jails.py index 675b6276..972a8c4b 100644 --- a/fail2ban/server/jails.py +++ b/fail2ban/server/jails.py @@ -62,14 +62,15 @@ class Jails(Mapping): DuplicateJailException If jail name is already present. """ - try: - self.__lock.acquire() + with self.__lock: if name in self._jails: - raise DuplicateJailException(name) + if noduplicates: + raise DuplicateJailException(name) else: self._jails[name] = Jail(name, backend, db) - finally: - self.__lock.release() + + def exists(self, name): + return name in self._jails def __getitem__(self, name): try: diff --git a/fail2ban/server/server.py b/fail2ban/server/server.py index 51487ed7..041b0983 100644 --- a/fail2ban/server/server.py +++ b/fail2ban/server/server.py @@ -67,6 +67,7 @@ class Server: self.__db = None self.__daemon = daemon self.__transm = Transmitter(self) + self.__reload_state = {} #self.__asyncServer = AsyncServer(self.__transm) self.__asyncServer = None self.__logLevel = None @@ -184,41 +185,105 @@ class Server: self.quit = lambda: False def addJail(self, name, backend): - self.__jails.add(name, backend, self.__db) + addflg = True + if self.__reload_state.get(name) and self.__jails.exists(name): + jail = self.__jails[name] + # if backend switch - restart instead of reload: + if jail.backend == backend: + addflg = False + logSys.info("Reload jail %r", name) + # prevent to reload the same jail twice (temporary keep it in state, needed to commit reload): + self.__reload_state[name] = None + else: + logSys.info("Restart jail %r (reason: %r != %r)", name, jail.backend, backend) + self.delJail(name, stop=True) + # prevent to start the same jail twice (no reload more - restart): + del self.__reload_state[name] + if addflg: + self.__jails.add(name, backend, self.__db) if self.__db is not None: self.__db.addJail(self.__jails[name]) - def delJail(self, name): + def delJail(self, name, stop=True): + jail = self.__jails[name] + if stop and jail.isAlive(): + logSys.debug("Stopping jail %r" % name) + jail.stop() if self.__db is not None: - self.__db.delJail(self.__jails[name]) + self.__db.delJail(jail) del self.__jails[name] def startJail(self, name): - try: - self.__lock.acquire() - if not self.__jails[name].isAlive(): - self.__jails[name].start() - finally: - self.__lock.release() + with self.__lock: + jail = self.__jails[name] + if not jail.isAlive(): + jail.start() + elif name in self.__reload_state: + logSys.info("Jail %r reloaded", name) + del self.__reload_state[name] + if jail.idle: + jail.idle = False def stopJail(self, name): - logSys.debug("Stopping jail %s" % name) - try: - self.__lock.acquire() - if self.__jails[name].isAlive(): - self.__jails[name].stop() - self.delJail(name) - finally: - self.__lock.release() + with self.__lock: + self.delJail(name, stop=True) def stopAllJail(self): logSys.info("Stopping all jails") - try: - self.__lock.acquire() - for jail in self.__jails.keys(): - self.stopJail(jail) - finally: - self.__lock.release() + with self.__lock: + for name in self.__jails.keys(): + self.delJail(name, stop=True) + + def reloadJails(self, name, opts, begin): + if begin: + # begin reload: + if self.__reload_state and (name == '--all' or self.__reload_state.get(name)): + raise ValueError('Reload already in progress') + logSys.info("Reload " + (("jail %s" % name) if name != '--all' else "all jails")) + with self.__lock: + # if single jail: + if name != '--all': + jail = None + # test jail exists (throws exception if not): + if "--if-exists" not in opts or self.__jails.exists(name): + jail = self.__jails[name] + if jail: + # first unban all ips (will be not restored after (re)start): + if "--unban" in opts: + self.setUnbanIP(name) + # stop if expected: + if "--restart" in opts: + self.stopJail(name) + else: + # first unban all ips (will be not restored after (re)start): + if "--unban" in opts: + self.setUnbanIP() + # stop if expected: + if "--restart" in opts: + self.stopAllJail() + # first set all affected jail(s) to idle and reset filter regex and other lists/dicts: + for jn, jail in self.__jails.iteritems(): + if name == '--all' or jn == name: + jail.idle = True + self.__reload_state[jn] = jail + jail.filter.reload(begin=True) + pass + else: + # end reload, all affected (or new) jails have already all new parameters (via stream) and (re)started: + with self.__lock: + deljails = [] + for jn, jail in self.__jails.iteritems(): + # still in reload state: + if jn in self.__reload_state: + # remove jails that are not reloaded (untouched, so not in new configuration) + deljails.append(jn) + else: + # commit (reload was finished): + jail.filter.reload(begin=False) + for jn in deljails: + self.delJail(jn) + self.__reload_state = {} + logSys.info("Reload finished.") def setIdleJail(self, name, value): self.__jails[name].idle = value @@ -309,7 +374,7 @@ class Server: logSys.debug(" failregex: %r", value) flt.addFailRegex(value) - def delFailRegex(self, name, index): + def delFailRegex(self, name, index=None): self.__jails[name].filter.delFailRegex(index) def getFailRegex(self, name): @@ -368,8 +433,20 @@ class Server: def setBanIP(self, name, value): return self.__jails[name].filter.addBannedIP(value) - def setUnbanIP(self, name, value): - self.__jails[name].actions.removeBannedIP(value) + def setUnbanIP(self, name=None, value=None): + if name is not None: + # in all jails: + jails = [self.__jails[name]] + else: + # single jail: + jails = self.__jails.values() + # unban given or all (if value is None): + cnt = 0 + for jail in jails: + cnt += jail.actions.removeBannedIP(value, ifexists=(name is None)) + if value and not cnt: + logSys.info("%s is not banned", value) + return cnt def getBanTime(self, name): return self.__jails[name].actions.getBanTime() @@ -420,7 +497,10 @@ class Server: if self.__logLevel == value: return try: - getLogger("fail2ban").setLevel(getattr(logging, value)) + ll = getattr(logging, value) + # don't change real log-level if running from the test cases: + getLogger("fail2ban").setLevel( + ll if DEF_LOGTARGET != "INHERITED" or ll < logging.DEBUG else DEF_LOGLEVEL) self.__logLevel = value except AttributeError: raise ValueError("Invalid log level %r" % value) diff --git a/fail2ban/server/transmitter.py b/fail2ban/server/transmitter.py index 698dad34..19cf51ef 100644 --- a/fail2ban/server/transmitter.py +++ b/fail2ban/server/transmitter.py @@ -27,7 +27,7 @@ __license__ = "GPL" import time import json -from ..helpers import getLogger +from ..helpers import getLogger, logging from .. import version # Gets the instance of the logger. @@ -52,13 +52,14 @@ class Transmitter: def proceed(self, command): # Deserialize object - logSys.debug("Command: %r", command) + logSys.log(5, "Command: %r", command) try: ret = self.__commandHandler(command) ack = 0, ret except Exception as e: - logSys.warning("Command %r has failed. Received %r" - % (command, e)) + logSys.warning("Command %r has failed. Received %r", + command, e, + exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) ack = 1, e return ack @@ -72,8 +73,8 @@ class Transmitter: return "pong" elif command[0] == "add": name = command[1] - if name == "all": - raise Exception("Reserved name") + if name == "--all": + raise Exception("Reserved name %r" % (name,)) try: backend = command[2] except IndexError: @@ -87,12 +88,31 @@ class Transmitter: elif command[0] == "stop": if len(command) == 1: self.__server.quit() - elif command[1] == "all": + elif command[1] == "--all": self.__server.stopAllJail() else: name = command[1] self.__server.stopJail(name) return None + elif command[0] == "reload": + opts = command[1:3] + try: + self.__server.reloadJails(*opts, begin=True) + for cmd in command[3]: + self.__commandHandler(cmd) + finally: + self.__server.reloadJails(*opts, begin=False) + return None + elif len(command) >= 2 and command[0] == "unban": + # unban in all jails: + value = command[1:] + # if all ips: + if len(value) == 1 and value[0] == "--all": + self.__server.setUnbanIP() + return + for value in value: + self.__server.setUnbanIP(None, value) + return None elif command[0] == "echo": return command[1:] elif command[0] == "sleep": @@ -265,7 +285,7 @@ class Transmitter: action = self.__server.getAction(name, actionname) if multiple: for cmd in command[3]: - logSys.debug(" %r", cmd) + logSys.log(5, " %r", cmd) actionkey = cmd[0] if callable(getattr(action, actionkey, None)): actionvalue = json.loads(cmd[1]) if len(cmd)>1 else {} diff --git a/fail2ban/tests/fail2banclienttestcase.py b/fail2ban/tests/fail2banclienttestcase.py index 6d4691fe..557f0ada 100644 --- a/fail2ban/tests/fail2banclienttestcase.py +++ b/fail2ban/tests/fail2banclienttestcase.py @@ -43,7 +43,7 @@ from .. import protocol from ..server import server from ..server.mytime import MyTime from ..server.utils import Utils -from .utils import LogCaptureTestCase, with_tmpdir, shutil, logging +from .utils import LogCaptureTestCase, logSys as DefLogSys, with_tmpdir, shutil, logging from ..helpers import getLogger @@ -69,7 +69,8 @@ fail2bancmdline.logSys = \ fail2banclient.logSys = \ fail2banserver.logSys = logSys -server.DEF_LOGTARGET = "/dev/null" +SRV_DEF_LOGTARGET = server.DEF_LOGTARGET +SRV_DEF_LOGLEVEL = server.DEF_LOGLEVEL def _test_output(*args): logSys.info(args[0]) @@ -111,17 +112,25 @@ fail2bancmdline.PRODUCTION = \ fail2banserver.PRODUCTION = False -def _out_file(fn): +def _out_file(fn, handle=logSys.debug): """Helper which outputs content of the file at HEAVYDEBUG loglevels""" - logSys.debug('---- ' + fn + ' ----') + handle('---- ' + fn + ' ----') for line in fileinput.input(fn): line = line.rstrip('\n') - logSys.debug(line) - logSys.debug('-'*30) + handle(line) + handle('-'*30) -def _start_params(tmp, use_stock=False, logtarget="/dev/null"): +def _write_file(fn, mode, *lines): + f = open(fn, mode) + f.write('\n'.join(lines)) + f.close() + + +def _start_params(tmp, use_stock=False, logtarget="/dev/null", db=":memory:"): cfg = pjoin(tmp, "config") + if db == 'auto': + db = pjoin(tmp, "f2b-db.sqlite3") if use_stock and STOCK: # copy config (sub-directories as alias): def ig_dirs(dir, files): @@ -147,8 +156,7 @@ def _start_params(tmp, use_stock=False, logtarget="/dev/null"): else: # just empty config directory without anything (only fail2ban.conf/jail.conf): os.mkdir(cfg) - f = open(pjoin(cfg, "fail2ban.conf"), "w") - f.write('\n'.join(( + _write_file(pjoin(cfg, "fail2ban.conf"), "w", "[Definition]", "loglevel = INFO", "logtarget = " + logtarget, @@ -156,19 +164,16 @@ def _start_params(tmp, use_stock=False, logtarget="/dev/null"): "socket = " + pjoin(tmp, "f2b.sock"), "pidfile = " + pjoin(tmp, "f2b.pid"), "backend = polling", - "dbfile = :memory:", + "dbfile = " + db, "dbpurgeage = 1d", "", - ))) - f.close() - f = open(pjoin(cfg, "jail.conf"), "w") - f.write('\n'.join(( + ) + _write_file(pjoin(cfg, "jail.conf"), "w", "[INCLUDES]", "", "[DEFAULT]", "", "", - ))) - f.close() - if logSys.level < logging.DEBUG: # if HEAVYDEBUG + ) + if DefLogSys.level < logging.DEBUG: # if HEAVYDEBUG _out_file(pjoin(cfg, "fail2ban.conf")) _out_file(pjoin(cfg, "jail.conf")) # parameters (sock/pid and config, increase verbosity, set log, etc.): @@ -238,19 +243,78 @@ def with_kill_srv(f): _kill_srv(pidfile) return wrapper +def with_foreground_server_thread(startextra={}): + """Helper to decorate tests uses foreground server (as thread), started directly in test-cases + + To be used only in subclasses + """ + def _deco_wrapper(f): + @with_tmpdir + @wraps(f) + def wrapper(self, tmp, *args, **kwargs): + th = None + phase = dict() + try: + # started directly here, so prevent overwrite test cases logger with "INHERITED" + startparams = _start_params(tmp, logtarget="INHERITED", **startextra) + # because foreground block execution - start it in thread: + th = Thread( + name="_TestCaseWorker", + target=self._testStartForeground, + args=(tmp, startparams, phase) + ) + th.daemon = True + th.start() + try: + # wait for start thread: + Utils.wait_for(lambda: phase.get('start', None) is not None, MAX_WAITTIME) + self.assertTrue(phase.get('start', None)) + # wait for server (socket and ready): + self._wait_for_srv(tmp, True, startparams=startparams) + DefLogSys.info('=== within server: begin ===') + self.pruneLog() + # several commands to server in body of decorated function: + return f(self, tmp, startparams, *args, **kwargs) + finally: + DefLogSys.info('=== within server: end. ===') + self.pruneLog() + # stop: + self.execSuccess(startparams, "stop") + # wait for end: + Utils.wait_for(lambda: phase.get('end', None) is not None, MAX_WAITTIME) + self.assertTrue(phase.get('end', None)) + self.assertLogged("Shutdown successful", "Exiting Fail2ban") + finally: + if th: + # we start client/server directly in current process (new thread), + # so don't kill (same process) - if success, just wait for end of worker: + if phase.get('end', None): + th.join() + return wrapper + return _deco_wrapper + class Fail2banClientServerBase(LogCaptureTestCase): _orig_exit = Fail2banCmdLine._exit + def _setLogLevel(self, *args, **kwargs): + pass + def setUp(self): """Call before every test case.""" LogCaptureTestCase.setUp(self) + # prevent to switch the logging in the test cases (use inherited one): + server.DEF_LOGTARGET = "INHERITED" + server.DEF_LOGLEVEL = DefLogSys.level Fail2banCmdLine._exit = staticmethod(self._test_exit) def tearDown(self): """Call after every test case.""" Fail2banCmdLine._exit = self._orig_exit + # restore server log target: + server.DEF_LOGTARGET = SRV_DEF_LOGTARGET + server.DEF_LOGLEVEL = SRV_DEF_LOGLEVEL LogCaptureTestCase.tearDown(self) @staticmethod @@ -304,54 +368,6 @@ class Fail2banClientServerBase(LogCaptureTestCase): phase['end'] = True logSys.debug("end of test worker") - def with_foreground_server_thread(startextra={}): - """Helper to decorate tests uses foreground server (as thread), started directly in test-cases - - To be used only in subclasses - """ - def _deco_wrapper(f): - @with_tmpdir - @wraps(f) - def wrapper(self, tmp, *args, **kwargs): - th = None - phase = dict() - try: - # started directly here, so prevent overwrite test cases logger with "INHERITED" - startparams = _start_params(tmp, logtarget="INHERITED", **startextra) - # because foreground block execution - start it in thread: - th = Thread( - name="_TestCaseWorker", - target=self._testStartForeground, - args=(tmp, startparams, phase) - ) - th.daemon = True - th.start() - try: - # wait for start thread: - Utils.wait_for(lambda: phase.get('start', None) is not None, MAX_WAITTIME) - self.assertTrue(phase.get('start', None)) - # wait for server (socket and ready): - self._wait_for_srv(tmp, True, startparams=startparams) - self.pruneLog() - # several commands to server in body of decorated function: - return f(self, tmp, startparams, *args, **kwargs) - finally: - self.pruneLog() - # stop: - self.execSuccess(startparams, "stop") - # wait for end: - Utils.wait_for(lambda: phase.get('end', None) is not None, MAX_WAITTIME) - self.assertTrue(phase.get('end', None)) - self.assertLogged("Shutdown successful", "Exiting Fail2ban") - finally: - if th: - # we start client/server directly in current process (new thread), - # so don't kill (same process) - if success, just wait for end of worker: - if phase.get('end', None): - th.join() - return wrapper - return _deco_wrapper - @with_foreground_server_thread() def testStartForeground(self, tmp, startparams): # several commands to server: @@ -522,6 +538,24 @@ class Fail2banClientTest(Fail2banClientServerBase): self.assertLogged("Usage: ") self.pruneLog() + @with_tmpdir + def testClientFailCommands(self, tmp): + # started directly here, so prevent overwrite test cases logger with "INHERITED" + startparams = _start_params(tmp, logtarget="INHERITED") + + # not started: + self.execFailed(startparams, + "reload", "jail") + self.assertLogged("Could not find server") + self.pruneLog() + + # unexpected arg: + self.execFailed(startparams, + "--async", "reload", "--xxx", "jail") + self.assertLogged("Unexpected argument(s) for reload:") + self.pruneLog() + + def testVisualWait(self): sleeptime = 0.035 for verbose in (2, 0): @@ -626,3 +660,242 @@ class Fail2banServerTest(Fail2banClientServerBase): # again: self.assertTrue(_kill_srv(tmp)) self.assertLogged("cleanup: no pidfile for") + + @with_foreground_server_thread(startextra={'db': 'auto'}) + def testServerReloadTest(self, tmp, startparams): + """Very complicated test-case, that expected running server (foreground in thread). + + In this test-case, each phase is related from previous one, + so it cannot be splitted in multiple test cases. + + It uses file database (instead of :memory:), to restore bans and log-file positions, + after restart/reload between phases. + """ + cfg = pjoin(tmp, "config") + test1log = pjoin(tmp, "test1.log") + test2log = pjoin(tmp, "test2.log") + test3log = pjoin(tmp, "test3.log") + + def _write_jail_cfg(enabled=[1, 2]): + _write_file(pjoin(cfg, "jail.conf"), "w", + "[INCLUDES]", "", + "[DEFAULT]", "", + "maxretry = 3", + "findtime = 10m", + "failregex = ^\s*failure (401|403) from ", + "", + "[test-jail1]", "backend = polling", "filter =", "action =", + "logpath = " + test1log, + " " + test2log if 2 in enabled else "", + " " + test3log if 2 in enabled else "", + "failregex = ^\s*failure (401|403) from ", + " ^\s*error (401|403) from " if 2 in enabled else "", + "enabled = true" if 1 in enabled else "", + "", + "[test-jail2]", "backend = polling", "filter =", "action =", + "logpath = " + test2log, + "enabled = true" if 2 in enabled else "", + ) + if DefLogSys.level < logging.DEBUG: # if HEAVYDEBUG + _out_file(pjoin(cfg, "jail.conf")) + + _write_jail_cfg(enabled=[1]) + _write_file(test1log, "w", *((str(int(MyTime.time())) + " failure 401 from 192.0.2.1: test 1",) * 3)) + _write_file(test2log, "w") + _write_file(test3log, "w") + + # reload and wait for ban: + self.pruneLog("[test-phase 1]") + if DefLogSys.level < logging.DEBUG: # if HEAVYDEBUG + _out_file(test1log) + self.execSuccess(startparams, "reload") + self.assertTrue( + Utils.wait_for(lambda: self._is_logged("[test-jail1] Ban 192.0.2.1"), MAX_WAITTIME / 5.0)) + self.assertLogged("Added logfile: %r" % test1log) + + # enable both jails, 3 logs for jail1, etc... + # truncate test-log - we should not find unban/ban again by reload: + self.pruneLog("[test-phase 2a]") + _write_jail_cfg() + _write_file(test1log, "w+") + if DefLogSys.level < logging.DEBUG: # if HEAVYDEBUG + _out_file(test1log) + self.execSuccess(startparams, "reload") + self.assertTrue( + Utils.wait_for(lambda: self._is_logged("Reload finished."), MAX_WAITTIME / 5.0)) + # test not unbanned / banned again: + self.assertNotLogged( + "[test-jail1] Unban 192.0.2.1", + "[test-jail1] Ban 192.0.2.1", all=True) + # test 2 new log files: + self.assertLogged( + "Added logfile: %r" % test2log, + "Added logfile: %r" % test3log, all=True) + # test 1 new jail: + self.assertLogged( + "Creating new jail 'test-jail2'", + "Jail 'test-jail2' started", all=True) + + # write new failures: + self.pruneLog("[test-phase 2b]") + _write_file(test2log, "w+", *( + (str(int(MyTime.time())) + " error 403 from 192.0.2.2: test 2",) * 3 + + (str(int(MyTime.time())) + " error 403 from 192.0.2.3: test 2",) * 3 + + (str(int(MyTime.time())) + " failure 401 from 192.0.2.4: test 2",) * 3 + )) + if DefLogSys.level < logging.DEBUG: # if HEAVYDEBUG + _out_file(test2log) + # test all will be found in jail1 and one in jail2: + self.assertTrue( + Utils.wait_for(lambda: \ + self._is_logged("[test-jail1] Ban 192.0.2.2") and + self._is_logged("[test-jail1] Ban 192.0.2.3") and + self._is_logged("[test-jail1] Ban 192.0.2.4") and + self._is_logged("[test-jail2] Ban 192.0.2.4") + , MAX_WAITTIME / 5.0)) + # test ips at all not visible for jail2: + self.assertNotLogged( + "[test-jail2] Found 192.0.2.2", + "[test-jail2] Ban 192.0.2.2", + "[test-jail2] Found 192.0.2.3", + "[test-jail2] Ban 192.0.2.3", all=True) + + # rotate logs: + _write_file(test1log, "w+") + _write_file(test2log, "w+") + + # restart jail without unban all: + self.pruneLog("[test-phase 2c]") + self.execSuccess(startparams, + "restart", "test-jail2") + self.assertTrue( + Utils.wait_for(lambda: \ + self._is_logged("Jail 'test-jail2' started") and + self._is_logged("[test-jail2] Ban 192.0.2.4") + , MAX_WAITTIME / 5.0)) + # stop/start and ban/unban: + self.assertLogged( + "Jail 'test-jail2' stopped", + "Jail 'test-jail2' started", + "[test-jail2] Unban 192.0.2.4", + "[test-jail2] Ban 192.0.2.4", all=True + ) + + # restart jail with unban all: + self.pruneLog("[test-phase 2d]") + self.execSuccess(startparams, + "restart", "--unban", "test-jail2") + self.assertTrue( + Utils.wait_for(lambda: self._is_logged("Jail 'test-jail2' started"), + MAX_WAITTIME / 5.0)) + self.assertLogged( + "Jail 'test-jail2' stopped", + "Jail 'test-jail2' started", + "[test-jail2] Unban 192.0.2.4", all=True + ) + # no more ban (unbanned all): + self.assertNotLogged( + "[test-jail2] Ban 192.0.2.4", all=True + ) + + # reload jail1 without restart (without ban/unban): + self.pruneLog("[test-phase 3]") + self.execSuccess(startparams, "reload", "test-jail1") + self.assertTrue( + Utils.wait_for(lambda: self._is_logged("Reload finished."), MAX_WAITTIME / 5.0)) + self.assertLogged( + "Reload jail 'test-jail1'", + "Jail 'test-jail1' reloaded", all=True) + self.assertNotLogged( + "Reload jail 'test-jail2'", + "Jail 'test-jail2' reloaded", + "Jail 'test-jail1' started", all=True + ) + + # whole reload, but this time with jail1 only (jail2 should be stopped via configuration): + self.pruneLog("[test-phase 4]") + _write_jail_cfg(enabled=[1]) + self.execSuccess(startparams, "reload") + self.assertTrue( + Utils.wait_for(lambda: self._is_logged("Reload finished."), MAX_WAITTIME / 5.0)) + # test both jails should be reloaded: + self.assertLogged( + "Reload jail 'test-jail1'") + # test jail2 goes down: + self.assertLogged( + "Stopping jail 'test-jail2'", + "Jail 'test-jail2' stopped", all=True) + # test 2 log files removed: + self.assertLogged( + "Removed logfile: %r" % test2log, + "Removed logfile: %r" % test3log, all=True) + + # now write failures again and check already banned (jail1 was alive the whole time) and new bans occurred (jail1 was alive the whole time): + self.pruneLog("[test-phase 5]") + _write_file(test1log, "w+", *( + (str(int(MyTime.time())) + " failure 401 from 192.0.2.1: test 5",) * 3 + + (str(int(MyTime.time())) + " error 403 from 192.0.2.5: test 5",) * 3 + + (str(int(MyTime.time())) + " failure 401 from 192.0.2.6: test 5",) * 3 + )) + if DefLogSys.level < logging.DEBUG: # if HEAVYDEBUG + _out_file(test1log) + # test "failure" regexp still available: + self.assertTrue( + Utils.wait_for(lambda: \ + self._is_logged("[test-jail1] 192.0.2.1 already banned") and + self._is_logged("[test-jail1] Ban 192.0.2.6") + , MAX_WAITTIME / 5.0)) + self.assertLogged( + "[test-jail1] Found 192.0.2.1", + "[test-jail1] Found 192.0.2.6", all=True + ) + # test "error" regexp no more available: + self.assertNotLogged("[test-jail1] Found 192.0.2.5") + + # unban single ips: + self.pruneLog("[test-phase 6]") + self.execSuccess(startparams, + "--async", "unban", "192.0.2.5", "192.0.2.6") + self.assertLogged( + "192.0.2.5 is not banned", + "[test-jail1] Unban 192.0.2.6", all=True + ) + + # reload all (one jail) with unban all: + self.pruneLog("[test-phase 7]") + self.execSuccess(startparams, + "reload", "--unban") + self.assertTrue( + Utils.wait_for(lambda: self._is_logged("Reload finished."), MAX_WAITTIME / 5.0)) + # reloads unbanned all: + self.assertLogged( + "Jail 'test-jail1' reloaded", + "[test-jail1] Unban 192.0.2.1", + "[test-jail1] Unban 192.0.2.2", + "[test-jail1] Unban 192.0.2.3", + "[test-jail1] Unban 192.0.2.4", all=True + ) + # no restart occurred, no more ban (unbanned all using option "--unban"): + self.assertNotLogged( + "Jail 'test-jail1' stopped", + "Jail 'test-jail1' started", + "[test-jail1] Ban 192.0.2.1", + "[test-jail1] Ban 192.0.2.2", + "[test-jail1] Ban 192.0.2.3", + "[test-jail1] Ban 192.0.2.4", all=True + ) + + # several small cases: + self.pruneLog("[test-phase end-1]") + # wrong jail (not-started): + self.execFailed(startparams, + "--async", "reload", "test-jail2") + self.assertLogged("the jail 'test-jail2' does not exist") + self.pruneLog() + # unavailable jail (but exit 0), using --if-exists option: + self.execSuccess(startparams, + "--async", "reload", "--if-exists", "test-jail2") + self.assertNotLogged( + "Creating new jail 'test-jail2'", + "Jail 'test-jail2' started", all=True) + self.pruneLog() diff --git a/fail2ban/tests/servertestcase.py b/fail2ban/tests/servertestcase.py index 12bbb2f7..3ca8049b 100644 --- a/fail2ban/tests/servertestcase.py +++ b/fail2ban/tests/servertestcase.py @@ -240,7 +240,7 @@ class Transmitter(TransmitterBase): self.transm.proceed(["add", self.jailName, "polling"])[0], 1) # All name is reserved self.assertEqual( - self.transm.proceed(["add", "all", "polling"])[0], 1) + self.transm.proceed(["add", "--all", "polling"])[0], 1) def testStartStopJail(self): self.assertEqual( @@ -267,7 +267,7 @@ class Transmitter(TransmitterBase): self.assertTrue( Utils.wait_for( lambda: self.server.isAlive(2) and not isinstance(self.transm.proceed(["status", self.jailName]), RuntimeError), 3) ) - self.assertEqual(self.transm.proceed(["stop", "all"]), (0, None)) + self.assertEqual(self.transm.proceed(["stop", "--all"]), (0, None)) self.assertTrue( Utils.wait_for( lambda: not len(self.server._Server__jails), 3) ) self.assertNotIn(self.jailName, self.server._Server__jails) self.assertNotIn("TestJail2", self.server._Server__jails) diff --git a/fail2ban/tests/utils.py b/fail2ban/tests/utils.py index bdc1c189..6eaf560b 100644 --- a/fail2ban/tests/utils.py +++ b/fail2ban/tests/utils.py @@ -119,6 +119,7 @@ def getOptParser(doc=""): def initProcess(opts): # Logger: + global logSys logSys = getLogger("fail2ban") # Numerical level of verbosity corresponding to a log "level" @@ -577,7 +578,8 @@ class LogCaptureTestCase(unittest.TestCase): print("") logSys.handlers += self._old_handlers logSys.debug('='*10 + ' %s ' + '='*20, self.id()) - logSys.setLevel(logging.DEBUG) + else: + logSys.setLevel(logging.DEBUG) def tearDown(self): """Call after every test case.""" @@ -638,8 +640,10 @@ class LogCaptureTestCase(unittest.TestCase): if s_ in logged: # pragma: no cover self.fail("%r was found in the log: ===\n%s===" % (s_, logged)) - def pruneLog(self): + def pruneLog(self, logphase=None): self._log.truncate(0) + if logphase: + logSys.debug('='*5 + ' %s ' + '='*5, logphase) def getLog(self): return self._log.getvalue() From 8c26cada27b67eed8d7b946aaafc3469c129edb5 Mon Sep 17 00:00:00 2001 From: sebres Date: Wed, 7 Sep 2016 22:06:11 +0200 Subject: [PATCH 03/27] temp commit: partially cherry picked from ban-time-incr branch --- fail2ban/protocol.py | 4 +- fail2ban/server/actions.py | 2 +- fail2ban/server/database.py | 43 +++++++++++++++++ fail2ban/server/jail.py | 24 +++++++--- fail2ban/server/ticket.py | 11 +++++ fail2ban/tests/fail2banclienttestcase.py | 59 ++++++++++++++---------- 6 files changed, 108 insertions(+), 35 deletions(-) diff --git a/fail2ban/protocol.py b/fail2ban/protocol.py index 147cd38d..6299794e 100644 --- a/fail2ban/protocol.py +++ b/fail2ban/protocol.py @@ -52,9 +52,9 @@ protocol = [ ["restart [--unban] [--if-exists] ", "restarts the jail (alias for 'reload --restart ... ')"], ["reload [--restart] [--unban] [--all]", "reloads the configuration without restarting of the server, the option '--restart' activates completely restarting of affected jails, thereby unbans IP addresses (if option '--unban' specified)"], ["reload [--restart] [--unban] [--if-exists] ", "reloads the jail , or restarts it (if option '--restart' specified)"], -["unban --all", "unbans all IP addresses (in all jails)"], -["unban ... ", "unbans (in all jails)"], ["stop", "stops all jails and terminate the server"], +["unban --all", "unbans all IP addresses (in all jails and database)"], +["unban ... ", "unbans (in all jails and database)"], ["status", "gets the current status of the server"], ["ping", "tests if the server is alive"], ["echo", "for internal usage, returns back and outputs a given string"], diff --git a/fail2ban/server/actions.py b/fail2ban/server/actions.py index 2fab02cd..8c60e55f 100644 --- a/fail2ban/server/actions.py +++ b/fail2ban/server/actions.py @@ -320,7 +320,7 @@ class Actions(JailThread, Mapping): aInfo["ipfailures"] = lambda: mi4ip(True).getAttempt() aInfo["ipjailfailures"] = lambda: mi4ip().getAttempt() if self.__banManager.addBanTicket(bTicket): - logSys.notice("[%s] Ban %s" % (self._jail.name, aInfo["ip"])) + logSys.notice("[%s] %sBan %s", self._jail.name, ('' if not bTicket.getRestored() else 'Restore '), ip) for name, action in self._actions.iteritems(): try: action.ban(aInfo.copy()) diff --git a/fail2ban/server/database.py b/fail2ban/server/database.py index 4e2dddf1..fc544be4 100644 --- a/fail2ban/server/database.py +++ b/fail2ban/server/database.py @@ -576,6 +576,49 @@ class Fail2BanDb(object): self._bansMergedCache[cacheKey] = tickets if ip is None else ticket return tickets if ip is None else ticket + @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, data FROM bans WHERE jail=?" + queryArgs.append(jail.name) + else: + query = "SELECT ip, max(timeofban), data FROM bans WHERE 1" + if ip is not None: + query += " AND ip=?" + queryArgs.append(ip) + 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, data in results: + #TODO: Implement data parts once arbitrary match keys completed + ticket = FailTicket(banip, timeofban, matches) + ticket.setAttempt(failures) + matches = [] + failures = 0 + matches.extend(data['matches']) + failures += data['failures'] + ticket.setAttempt(failures) + tickets.append(ticket) + + return tickets if ip is None else ticket + @commitandrollback def purge(self, cur): """Purge old bans, jails and log files from database. diff --git a/fail2ban/server/jail.py b/fail2ban/server/jail.py index a5dc1119..7e05a025 100644 --- a/fail2ban/server/jail.py +++ b/fail2ban/server/jail.py @@ -194,7 +194,7 @@ class Jail(object): Used by filter to add a failure for banning. """ self.__queue.put(ticket) - if self.database is not None: + if not ticket.getRestored() and self.database is not None: self.database.addBan(self, ticket) def getFailTicket(self): @@ -207,6 +207,21 @@ class Jail(object): except Queue.Empty: return False + def restoreCurrentBans(self): + """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): + #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. @@ -215,12 +230,7 @@ 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 %r started", self.name) def stop(self): diff --git a/fail2ban/server/ticket.py b/fail2ban/server/ticket.py index 65ed83c3..8d07fcf3 100644 --- a/fail2ban/server/ticket.py +++ b/fail2ban/server/ticket.py @@ -36,6 +36,8 @@ logSys = getLogger(__name__) class Ticket: + RESTORED = 0x01 + def __init__(self, ip=None, time=None, matches=None, data={}, ticket=None): """Ticket constructor @@ -126,6 +128,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/tests/fail2banclienttestcase.py b/fail2ban/tests/fail2banclienttestcase.py index 557f0ada..07bbd913 100644 --- a/fail2ban/tests/fail2banclienttestcase.py +++ b/fail2ban/tests/fail2banclienttestcase.py @@ -58,6 +58,7 @@ SERVER = "fail2ban-server" BIN = dirname(Fail2banServer.getServerPath()) MAX_WAITTIME = 30 if not unittest.F2B.fast else 5 +MID_WAITTIME = MAX_WAITTIME / 2.5 ## # Several wrappers and settings for proper testing: @@ -663,14 +664,14 @@ class Fail2banServerTest(Fail2banClientServerBase): @with_foreground_server_thread(startextra={'db': 'auto'}) def testServerReloadTest(self, tmp, startparams): - """Very complicated test-case, that expected running server (foreground in thread). - - In this test-case, each phase is related from previous one, - so it cannot be splitted in multiple test cases. - - It uses file database (instead of :memory:), to restore bans and log-file positions, - after restart/reload between phases. - """ + # Very complicated test-case, that expected running server (foreground in thread). + # + # In this test-case, each phase is related from previous one, + # so it cannot be splitted in multiple test cases. + # Additionaly many log-messages used as ready-sign (to wait for end of phase). + # + # Used file database (instead of :memory:), to restore bans and log-file positions, + # after restart/reload between phases. cfg = pjoin(tmp, "config") test1log = pjoin(tmp, "test1.log") test2log = pjoin(tmp, "test2.log") @@ -710,7 +711,7 @@ class Fail2banServerTest(Fail2banClientServerBase): _out_file(test1log) self.execSuccess(startparams, "reload") self.assertTrue( - Utils.wait_for(lambda: self._is_logged("[test-jail1] Ban 192.0.2.1"), MAX_WAITTIME / 5.0)) + Utils.wait_for(lambda: self._is_logged("[test-jail1] Ban 192.0.2.1"), MID_WAITTIME)) self.assertLogged("Added logfile: %r" % test1log) # enable both jails, 3 logs for jail1, etc... @@ -722,7 +723,7 @@ class Fail2banServerTest(Fail2banClientServerBase): _out_file(test1log) self.execSuccess(startparams, "reload") self.assertTrue( - Utils.wait_for(lambda: self._is_logged("Reload finished."), MAX_WAITTIME / 5.0)) + Utils.wait_for(lambda: self._is_logged("Reload finished."), MID_WAITTIME)) # test not unbanned / banned again: self.assertNotLogged( "[test-jail1] Unban 192.0.2.1", @@ -741,7 +742,8 @@ class Fail2banServerTest(Fail2banClientServerBase): _write_file(test2log, "w+", *( (str(int(MyTime.time())) + " error 403 from 192.0.2.2: test 2",) * 3 + (str(int(MyTime.time())) + " error 403 from 192.0.2.3: test 2",) * 3 + - (str(int(MyTime.time())) + " failure 401 from 192.0.2.4: test 2",) * 3 + (str(int(MyTime.time())) + " failure 401 from 192.0.2.4: test 2",) * 3 + + (str(int(MyTime.time())) + " failure 401 from 192.0.2.8: test 2",) * 3 )) if DefLogSys.level < logging.DEBUG: # if HEAVYDEBUG _out_file(test2log) @@ -751,8 +753,10 @@ class Fail2banServerTest(Fail2banClientServerBase): self._is_logged("[test-jail1] Ban 192.0.2.2") and self._is_logged("[test-jail1] Ban 192.0.2.3") and self._is_logged("[test-jail1] Ban 192.0.2.4") and - self._is_logged("[test-jail2] Ban 192.0.2.4") - , MAX_WAITTIME / 5.0)) + self._is_logged("[test-jail1] Ban 192.0.2.8") and + self._is_logged("[test-jail2] Ban 192.0.2.4") and + self._is_logged("[test-jail2] Ban 192.0.2.8") + , MID_WAITTIME)) # test ips at all not visible for jail2: self.assertNotLogged( "[test-jail2] Found 192.0.2.2", @@ -771,14 +775,17 @@ class Fail2banServerTest(Fail2banClientServerBase): self.assertTrue( Utils.wait_for(lambda: \ self._is_logged("Jail 'test-jail2' started") and - self._is_logged("[test-jail2] Ban 192.0.2.4") - , MAX_WAITTIME / 5.0)) - # stop/start and ban/unban: + self._is_logged("[test-jail2] Restore Ban 192.0.2.4") and + self._is_logged("[test-jail2] Restore Ban 192.0.2.8") + , MID_WAITTIME)) + # stop/start and unban/restore ban: self.assertLogged( "Jail 'test-jail2' stopped", "Jail 'test-jail2' started", "[test-jail2] Unban 192.0.2.4", - "[test-jail2] Ban 192.0.2.4", all=True + "[test-jail2] Unban 192.0.2.8", + "[test-jail2] Restore Ban 192.0.2.4", + "[test-jail2] Restore Ban 192.0.2.8", all=True ) # restart jail with unban all: @@ -787,22 +794,24 @@ class Fail2banServerTest(Fail2banClientServerBase): "restart", "--unban", "test-jail2") self.assertTrue( Utils.wait_for(lambda: self._is_logged("Jail 'test-jail2' started"), - MAX_WAITTIME / 5.0)) + MID_WAITTIME)) self.assertLogged( "Jail 'test-jail2' stopped", "Jail 'test-jail2' started", - "[test-jail2] Unban 192.0.2.4", all=True + "[test-jail2] Unban 192.0.2.4", + "[test-jail2] Unban 192.0.2.8", all=True ) # no more ban (unbanned all): self.assertNotLogged( - "[test-jail2] Ban 192.0.2.4", all=True + "[test-jail2] Ban 192.0.2.4", + "[test-jail2] Ban 192.0.2.8", all=True ) # reload jail1 without restart (without ban/unban): self.pruneLog("[test-phase 3]") self.execSuccess(startparams, "reload", "test-jail1") self.assertTrue( - Utils.wait_for(lambda: self._is_logged("Reload finished."), MAX_WAITTIME / 5.0)) + Utils.wait_for(lambda: self._is_logged("Reload finished."), MID_WAITTIME)) self.assertLogged( "Reload jail 'test-jail1'", "Jail 'test-jail1' reloaded", all=True) @@ -817,7 +826,7 @@ class Fail2banServerTest(Fail2banClientServerBase): _write_jail_cfg(enabled=[1]) self.execSuccess(startparams, "reload") self.assertTrue( - Utils.wait_for(lambda: self._is_logged("Reload finished."), MAX_WAITTIME / 5.0)) + Utils.wait_for(lambda: self._is_logged("Reload finished."), MID_WAITTIME)) # test both jails should be reloaded: self.assertLogged( "Reload jail 'test-jail1'") @@ -844,7 +853,7 @@ class Fail2banServerTest(Fail2banClientServerBase): Utils.wait_for(lambda: \ self._is_logged("[test-jail1] 192.0.2.1 already banned") and self._is_logged("[test-jail1] Ban 192.0.2.6") - , MAX_WAITTIME / 5.0)) + , MID_WAITTIME)) self.assertLogged( "[test-jail1] Found 192.0.2.1", "[test-jail1] Found 192.0.2.6", all=True @@ -866,7 +875,7 @@ class Fail2banServerTest(Fail2banClientServerBase): self.execSuccess(startparams, "reload", "--unban") self.assertTrue( - Utils.wait_for(lambda: self._is_logged("Reload finished."), MAX_WAITTIME / 5.0)) + Utils.wait_for(lambda: self._is_logged("Reload finished."), MID_WAITTIME)) # reloads unbanned all: self.assertLogged( "Jail 'test-jail1' reloaded", @@ -885,7 +894,7 @@ class Fail2banServerTest(Fail2banClientServerBase): "[test-jail1] Ban 192.0.2.4", all=True ) - # several small cases: + # several small cases (cover several parts): self.pruneLog("[test-phase end-1]") # wrong jail (not-started): self.execFailed(startparams, From d2ddc59c40687e7846fd9aeb12230d9668dbf532 Mon Sep 17 00:00:00 2001 From: sebres Date: Thu, 8 Sep 2016 15:38:36 +0200 Subject: [PATCH 04/27] build replacement of `` substitution corresponding parameter `usedns` - dns-part will be added only if `usedns` is not `no`; new replacement for `` in opposition to ``, for separate usage of 2 address groups only (regardless of `usedns`), `ip4` and `ip6` together, without host (dns) --- fail2ban/client/jailreader.py | 2 +- fail2ban/server/failregex.py | 23 +++++++++++++++-------- fail2ban/server/filter.py | 8 ++++---- fail2ban/tests/fail2banclienttestcase.py | 3 ++- 4 files changed, 22 insertions(+), 14 deletions(-) diff --git a/fail2ban/client/jailreader.py b/fail2ban/client/jailreader.py index e3c4731c..9d01a693 100644 --- a/fail2ban/client/jailreader.py +++ b/fail2ban/client/jailreader.py @@ -106,7 +106,7 @@ class JailReader(ConfigReader): ["int", "maxretry", None], ["string", "findtime", None], ["string", "bantime", None], - ["string", "usedns", None], + ["string", "usedns", None], # be sure usedns is before all regex(s) in stream ["string", "failregex", None], ["string", "ignoreregex", None], ["string", "ignorecommand", None], diff --git a/fail2ban/server/failregex.py b/fail2ban/server/failregex.py index 12b8986a..7c512609 100644 --- a/fail2ban/server/failregex.py +++ b/fail2ban/server/failregex.py @@ -40,11 +40,11 @@ class Regex: # avoid construction of invalid object. # @param value the regular expression - def __init__(self, regex): + def __init__(self, regex, **kwargs): self._matchCache = None # Perform shortcuts expansions. # Resolve "" tag using default regular expression for host: - regex = Regex._resolveHostTag(regex) + regex = Regex._resolveHostTag(regex, **kwargs) # Replace "" with regular expression for multiple lines. regexSplit = regex.split("") regex = regexSplit[0] @@ -69,22 +69,29 @@ class Regex: # @return the replaced regular expression as string @staticmethod - def _resolveHostTag(regex): - # 3 groups instead of - separated ipv4, ipv6 and host - regex = regex.replace("", - r"""(?:(?:::f{4,6}:)?(?P(?:\d{1,3}\.){3}\d{1,3})|\[?(?P(?:[0-9a-fA-F]{1,4}::?|::){1,7}(?:[0-9a-fA-F]{1,4}|(?<=:):))\]?|(?P[\w\-.^_]*\w))""") + def _resolveHostTag(regex, useDns="yes"): # separated ipv4: + r_host = [] r = r"""(?:::f{4,6}:)?(?P(?:\d{1,3}\.){3}\d{1,3})""" regex = regex.replace("", r); # self closed regex = regex.replace("", r); # closed + r_host.append(r) # separated ipv6: r = r"""(?P(?:[0-9a-fA-F]{1,4}::?|::){1,7}(?:[0-9a-fA-F]{1,4}?|(?<=:):))""" regex = regex.replace("", r); # self closed regex = regex.replace("", r); # closed + r_host.append(r"""\[?%s\]?""" % (r,)); # enclose ipv6 in optional [] in host-regex + # 2 address groups instead of - in opposition to ``, + # for separate usage of 2 address groups only (regardless of `usedns`), `ip4` and `ip6` together + regex = regex.replace("", "(?:%s)" % ("|".join(r_host),)) # separated dns: r = r"""(?P[\w\-.^_]*\w)""" regex = regex.replace("", r); # self closed regex = regex.replace("", r); # closed + if useDns not in ("no",): + r_host.append(r) + # 3 groups instead of - separated ipv4, ipv6 and host (dns) + regex = regex.replace("", "(?:%s)" % ("|".join(r_host),)) # default failure-id as no space tag: regex = regex.replace("", r"""(?P\S+)"""); # closed # default failure port, like 80 or http : @@ -249,9 +256,9 @@ class FailRegex(Regex): # avoid construction of invalid object. # @param value the regular expression - def __init__(self, regex): + def __init__(self, regex, **kwargs): # Initializes the parent. - Regex.__init__(self, regex) + Regex.__init__(self, regex, **kwargs) # Check for group "dns", "ip4", "ip6", "fid" if not [grp for grp in FAILURE_ID_GROPS if grp in self._regexObj.groupindex]: raise RegexException("No failure-id group in '%s'" % self._regex) diff --git a/fail2ban/server/filter.py b/fail2ban/server/filter.py index 4c67470e..1c466c01 100644 --- a/fail2ban/server/filter.py +++ b/fail2ban/server/filter.py @@ -134,12 +134,12 @@ class Filter(JailThread): def addFailRegex(self, value): try: - regex = FailRegex(value) + regex = FailRegex(value, useDns=self.__useDns) self.__failRegex.append(regex) if "\n" in regex.getRegex() and not self.getMaxLines() > 1: logSys.warning( - "Mutliline regex set for jail '%s' " - "but maxlines not greater than 1") + "Mutliline regex set for jail %r " + "but maxlines not greater than 1", self.jail.name) except RegexException as e: logSys.error(e) raise e @@ -176,7 +176,7 @@ class Filter(JailThread): def addIgnoreRegex(self, value): try: - regex = Regex(value) + regex = Regex(value, useDns=self.__useDns) self.__ignoreRegex.append(regex) except RegexException as e: logSys.error(e) diff --git a/fail2ban/tests/fail2banclienttestcase.py b/fail2ban/tests/fail2banclienttestcase.py index 07bbd913..1ce35d92 100644 --- a/fail2ban/tests/fail2banclienttestcase.py +++ b/fail2ban/tests/fail2banclienttestcase.py @@ -58,7 +58,7 @@ SERVER = "fail2ban-server" BIN = dirname(Fail2banServer.getServerPath()) MAX_WAITTIME = 30 if not unittest.F2B.fast else 5 -MID_WAITTIME = MAX_WAITTIME / 2.5 +MID_WAITTIME = MAX_WAITTIME ## # Several wrappers and settings for proper testing: @@ -681,6 +681,7 @@ class Fail2banServerTest(Fail2banClientServerBase): _write_file(pjoin(cfg, "jail.conf"), "w", "[INCLUDES]", "", "[DEFAULT]", "", + "usedns = no", "maxretry = 3", "findtime = 10m", "failregex = ^\s*failure (401|403) from ", From 27f6fc083af5be470d49137e0cd4ecedcd54db52 Mon Sep 17 00:00:00 2001 From: sebres Date: Thu, 8 Sep 2016 18:27:55 +0200 Subject: [PATCH 05/27] optimized BanManager: increase performance, fewer system load, try to prevent memory leakage: - better ban/unban handling within actions (e.g. used dict instead of list) - don't copy bans resp. its list on some operations; - added new unbantime handling to relieve unBanList (prevent permanent searching for tickets to unban) - prefer failure-ID as identifier of the ticket to its IP (most of the time the same, but it can be something else e.g. user name in some complex jails, as introduced in 0.10) --- fail2ban/server/actions.py | 32 ++++-- fail2ban/server/banmanager.py | 152 +++++++++++++-------------- fail2ban/server/ticket.py | 16 ++- fail2ban/tests/banmanagertestcase.py | 2 +- 4 files changed, 108 insertions(+), 94 deletions(-) diff --git a/fail2ban/server/actions.py b/fail2ban/server/actions.py index 8c60e55f..244d1e68 100644 --- a/fail2ban/server/actions.py +++ b/fail2ban/server/actions.py @@ -204,7 +204,7 @@ class Actions(JailThread, Mapping): if db and self._jail.database is not None: self._jail.database.delBan(self._jail, ip) # Find the ticket with the IP. - ticket = self.__banManager.getTicketByIP(ip) + ticket = self.__banManager.getTicketByID(ip) if ticket is not None: # Unban the IP. self.__unBan(ticket) @@ -303,8 +303,11 @@ class Actions(JailThread, Mapping): bool True if an IP address get banned. """ - ticket = self._jail.getFailTicket() - if ticket: + cnt = 0 + while cnt < 100: + ticket = self._jail.getFailTicket() + if not ticket: + break aInfo = CallingMap() bTicket = BanManager.createBanTicket(ticket) ip = bTicket.getIP() @@ -320,6 +323,7 @@ class Actions(JailThread, Mapping): aInfo["ipfailures"] = lambda: mi4ip(True).getAttempt() aInfo["ipjailfailures"] = lambda: mi4ip().getAttempt() if self.__banManager.addBanTicket(bTicket): + cnt += 1 logSys.notice("[%s] %sBan %s", self._jail.name, ('' if not bTicket.getRestored() else 'Restore '), ip) for name, action in self._actions.iteritems(): try: @@ -330,19 +334,26 @@ class Actions(JailThread, Mapping): "info '%r': %s", self._jail.name, name, aInfo, e, exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) - return True else: - logSys.notice("[%s] %s already banned" % (self._jail.name, - aInfo["ip"])) - return False + logSys.notice("[%s] %s already banned", self._jail.name, ip) + if cnt: + logSys.debug("Banned %s / %s, %s ticket(s) in %r", cnt, + self.__banManager.getBanTotal(), self.__banManager.size(), self._jail.name) + return cnt def __checkUnBan(self): """Check for IP address to unban. Unban IP addresses which are outdated. """ - for ticket in self.__banManager.unBanList(MyTime.time()): + lst = self.__banManager.unBanList(MyTime.time()) + for ticket in lst: self.__unBan(ticket) + cnt = len(lst) + if cnt: + logSys.debug("Unbanned %s, %s ticket(s) in %r", + cnt, self.__banManager.size(), self._jail.name) + return cnt def __flushBan(self, db=False): """Flush the ban list. @@ -358,7 +369,10 @@ class Actions(JailThread, Mapping): self._jail.database.delBan(self._jail, ip) # unban ip: self.__unBan(ticket) - return len(lst) + cnt = len(lst) + logSys.debug("Unbanned %s, %s ticket(s) in %r", + cnt, self.__banManager.size(), self._jail.name) + return cnt def __unBan(self, ticket): """Unbans host corresponding to the ticket. diff --git a/fail2ban/server/banmanager.py b/fail2ban/server/banmanager.py index afa70685..e0a9e5ca 100644 --- a/fail2ban/server/banmanager.py +++ b/fail2ban/server/banmanager.py @@ -51,11 +51,13 @@ class BanManager: ## Mutex used to protect the ban list. self.__lock = Lock() ## The ban list. - self.__banList = list() + self.__banList = dict() ## The amount of time an IP address gets banned. self.__banTime = 600 ## Total number of banned IP address self.__banTotal = 0 + ## The time for next unban process (for performance and load reasons): + self.__nextUnbanTime = 0xFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFL ## # Set the ban time. @@ -64,11 +66,8 @@ class BanManager: # @param value the time def setBanTime(self, value): - try: - self.__lock.acquire() + with self.__lock: self.__banTime = int(value) - finally: - self.__lock.release() ## # Get the ban time. @@ -77,11 +76,8 @@ class BanManager: # @return the time def getBanTime(self): - try: - self.__lock.acquire() + with self.__lock: return self.__banTime - finally: - self.__lock.release() ## # Set the total number of banned address. @@ -89,11 +85,8 @@ class BanManager: # @param value total number def setBanTotal(self, value): - try: - self.__lock.acquire() + with self.__lock: self.__banTotal = value - finally: - self.__lock.release() ## # Get the total number of banned address. @@ -101,11 +94,8 @@ class BanManager: # @return the total number def getBanTotal(self): - try: - self.__lock.acquire() + with self.__lock: return self.__banTotal - finally: - self.__lock.release() ## # Returns a copy of the IP list. @@ -113,11 +103,8 @@ class BanManager: # @return IP list def getBanList(self): - try: - self.__lock.acquire() - return [m.getIP() for m in self.__banList] - finally: - self.__lock.release() + with self.__lock: + return self.__banList.keys() ## # Returns normalized value @@ -149,7 +136,7 @@ class BanManager: return return_dict self.__lock.acquire() try: - for banData in self.__banList: + for banData in self.__banList.values(): ip = banData.getIP() # Reference: http://www.team-cymru.org/Services/ip-to-asn.html#dns question = ip.getPTR( @@ -261,29 +248,31 @@ class BanManager: # @return True if the IP address is not in the ban list def addBanTicket(self, ticket): - try: - self.__lock.acquire() + with self.__lock: # check already banned - for oldticket in self.__banList: - if ticket.getIP() == oldticket.getIP(): - # if already permanent - btold, told = oldticket.getBanTime(self.__banTime), oldticket.getTime() - if btold == -1: - return False - # if given time is less than already banned time - btnew, tnew = ticket.getBanTime(self.__banTime), ticket.getTime() - if btnew != -1 and tnew + btnew <= told + btold: - return False - # we have longest ban - set new (increment) ban time - oldticket.setTime(tnew) - oldticket.setBanTime(btnew) + fid = ticket.getID() + oldticket = self.__banList.get(fid) + if oldticket: + # if already permanent + btold, told = oldticket.getBanTime(self.__banTime), oldticket.getTime() + if btold == -1: return False + # if given time is less than already banned time + btnew, tnew = ticket.getBanTime(self.__banTime), ticket.getTime() + if btnew != -1 and tnew + btnew <= told + btold: + return False + # we have longest ban - set new (increment) ban time + oldticket.setTime(tnew) + oldticket.setBanTime(btnew) + return False # not yet banned - add new - self.__banList.append(ticket) + self.__banList[fid] = ticket self.__banTotal += 1 + # correct next unban time: + eob = ticket.getEndOfBanTime(self.__banTime) + if self.__nextUnbanTime > eob: + self.__nextUnbanTime = eob return True - finally: - self.__lock.release() ## # Get the size of the ban list. @@ -291,11 +280,7 @@ class BanManager: # @return the size def size(self): - try: - self.__lock.acquire() - return len(self.__banList) - finally: - self.__lock.release() + return len(self.__banList) ## # Check if a ticket is in the list. @@ -306,10 +291,7 @@ class BanManager: # @return True if a ticket already exists def _inBanList(self, ticket): - for i in self.__banList: - if ticket.getIP() == i.getIP(): - return True - return False + return ticket.getID() in self.__banList ## # Get the list of IP address to unban. @@ -319,22 +301,39 @@ class BanManager: # @return the list of ticket to unban def unBanList(self, time): - try: - self.__lock.acquire() + with self.__lock: # Permanent banning if self.__banTime < 0: return list() - # Gets the list of ticket to remove. - unBanList = [ticket for ticket in self.__banList if ticket.isTimedOut(time, self.__banTime)] - + # Check next unban time: + if self.__nextUnbanTime > time: + return list() + + # Gets the list of ticket to remove (thereby correct next unban time). + unBanList = {} + self.__nextUnbanTime = 0xFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFL + for fid,ticket in self.__banList.iteritems(): + # current time greater as end of ban - timed out: + eob = ticket.getEndOfBanTime(self.__banTime) + if time > eob: + unBanList[fid] = ticket + elif self.__nextUnbanTime > eob: + self.__nextUnbanTime = eob + # Removes tickets. - self.__banList = [ticket for ticket in self.__banList - if ticket not in unBanList] + if len(unBanList): + if len(unBanList) / 2.0 <= len(self.__banList) / 3.0: + # few as 2/3 should be removed - remove particular items: + for fid in unBanList.iterkeys(): + del self.__banList[fid] + else: + # create new dictionary without items to be deleted: + self.__banList = dict((fid,ticket) for fid,ticket in self.__banList.iteritems() \ + if fid not in unBanList) - return unBanList - finally: - self.__lock.release() + # return list of tickets: + return unBanList.values() ## # Flush the ban list. @@ -343,28 +342,21 @@ class BanManager: # @return the complete ban list def flushBanList(self): - try: - self.__lock.acquire() - uBList = self.__banList - self.__banList = list() + with self.__lock: + uBList = self.__banList.values() + self.__banList = dict() return uBList - finally: - self.__lock.release() ## - # Gets the ticket for the specified IP. + # Gets the ticket for the specified ID (most of the time it is IP-address). # - # @return the ticket for the IP or False. - def getTicketByIP(self, ip): - try: - self.__lock.acquire() - - # Find the ticket the IP goes with and return it - for i, ticket in enumerate(self.__banList): - if ticket.getIP() == ip: - # Return the ticket after removing (popping) - # if from the ban list. - return self.__banList.pop(i) - finally: - self.__lock.release() + # @return the ticket or False. + def getTicketByID(self, fid): + with self.__lock: + try: + # Return the ticket after removing (popping) + # if from the ban list. + return self.__banList.pop(fid) + except KeyError: + pass return None # if none found diff --git a/fail2ban/server/ticket.py b/fail2ban/server/ticket.py index 8d07fcf3..4dc6ab88 100644 --- a/fail2ban/server/ticket.py +++ b/fail2ban/server/ticket.py @@ -96,8 +96,8 @@ class Ticket: def setBanTime(self, value): self._banTime = value; - def getBanTime(self, defaultBT = None): - return (self._banTime if not self._banTime is None else defaultBT); + def getBanTime(self, defaultBT=None): + return (self._banTime if self._banTime is not None else defaultBT) def setBanCount(self, value): self._banCount = value; @@ -108,8 +108,16 @@ class Ticket: def getBanCount(self): return self._banCount; - def isTimedOut(self, time, defaultBT = None): - bantime = (self._banTime if not self._banTime is None else defaultBT); + def getEndOfBanTime(self, defaultBT=None): + bantime = (self._banTime if self._banTime is not None else defaultBT) + # permanent + if bantime == -1: + return 0xFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFL + # unban time (end of ban): + return self._time + bantime + + def isTimedOut(self, time, defaultBT=None): + bantime = (self._banTime if self._banTime is not None else defaultBT) # permanent if bantime == -1: return False diff --git a/fail2ban/tests/banmanagertestcase.py b/fail2ban/tests/banmanagertestcase.py index f47dc848..c9f41c6c 100644 --- a/fail2ban/tests/banmanagertestcase.py +++ b/fail2ban/tests/banmanagertestcase.py @@ -70,7 +70,7 @@ class AddFailure(unittest.TestCase): self.assertFalse(self.__banManager.addBanTicket(ticket2)) self.assertEqual(self.__banManager.size(), 1) # pop ticket and check it was prolonged : - banticket = self.__banManager.getTicketByIP(ticket2.getIP()) + banticket = self.__banManager.getTicketByID(ticket2.getID()) self.assertEqual(banticket.getTime(), ticket2.getTime()) self.assertEqual(banticket.getTime(), ticket2.getTime()) self.assertEqual(banticket.getBanTime(), ticket2.getBanTime(self.__banManager.getBanTime())) From 8cba537f6ce75684d9d3fc7c33066f4876b78898 Mon Sep 17 00:00:00 2001 From: sebres Date: Thu, 8 Sep 2016 18:29:45 +0200 Subject: [PATCH 06/27] code review and use new logger-signals for waiting; + regenerated man-files --- fail2ban/protocol.py | 2 +- fail2ban/tests/fail2banclienttestcase.py | 44 ++++++++------ man/fail2ban-client.1 | 77 ++++++++++++++---------- man/fail2ban-regex.1 | 18 +++--- man/fail2ban-server.1 | 8 +-- man/fail2ban-testcases.1 | 14 +++-- 6 files changed, 95 insertions(+), 68 deletions(-) diff --git a/fail2ban/protocol.py b/fail2ban/protocol.py index 6299794e..879183e5 100644 --- a/fail2ban/protocol.py +++ b/fail2ban/protocol.py @@ -50,7 +50,7 @@ protocol = [ ["start", "starts the server and the jails"], ["restart", "restarts the server"], ["restart [--unban] [--if-exists] ", "restarts the jail (alias for 'reload --restart ... ')"], -["reload [--restart] [--unban] [--all]", "reloads the configuration without restarting of the server, the option '--restart' activates completely restarting of affected jails, thereby unbans IP addresses (if option '--unban' specified)"], +["reload [--restart] [--unban] [--all]", "reloads the configuration without restarting of the server, the option '--restart' activates completely restarting of affected jails, thereby can unban IP addresses (if option '--unban' specified)"], ["reload [--restart] [--unban] [--if-exists] ", "reloads the jail , or restarts it (if option '--restart' specified)"], ["stop", "stops all jails and terminate the server"], ["unban --all", "unbans all IP addresses (in all jails and database)"], diff --git a/fail2ban/tests/fail2banclienttestcase.py b/fail2ban/tests/fail2banclienttestcase.py index 1ce35d92..394a000f 100644 --- a/fail2ban/tests/fail2banclienttestcase.py +++ b/fail2ban/tests/fail2banclienttestcase.py @@ -712,8 +712,12 @@ class Fail2banServerTest(Fail2banClientServerBase): _out_file(test1log) self.execSuccess(startparams, "reload") self.assertTrue( - Utils.wait_for(lambda: self._is_logged("[test-jail1] Ban 192.0.2.1"), MID_WAITTIME)) + Utils.wait_for(lambda: \ + self._is_logged("Reload finished.") and + self._is_logged("1 ticket(s) in 'test-jail1") + , MID_WAITTIME)) self.assertLogged("Added logfile: %r" % test1log) + self.assertLogged("[test-jail1] Ban 192.0.2.1") # enable both jails, 3 logs for jail1, etc... # truncate test-log - we should not find unban/ban again by reload: @@ -751,13 +755,16 @@ class Fail2banServerTest(Fail2banClientServerBase): # test all will be found in jail1 and one in jail2: self.assertTrue( Utils.wait_for(lambda: \ - self._is_logged("[test-jail1] Ban 192.0.2.2") and - self._is_logged("[test-jail1] Ban 192.0.2.3") and - self._is_logged("[test-jail1] Ban 192.0.2.4") and - self._is_logged("[test-jail1] Ban 192.0.2.8") and - self._is_logged("[test-jail2] Ban 192.0.2.4") and - self._is_logged("[test-jail2] Ban 192.0.2.8") + self._is_logged("2 ticket(s) in 'test-jail2") and + self._is_logged("5 ticket(s) in 'test-jail1") , MID_WAITTIME)) + self.assertLogged( + "[test-jail1] Ban 192.0.2.2", + "[test-jail1] Ban 192.0.2.3", + "[test-jail1] Ban 192.0.2.4", + "[test-jail1] Ban 192.0.2.8", + "[test-jail2] Ban 192.0.2.4", + "[test-jail2] Ban 192.0.2.8", all=True) # test ips at all not visible for jail2: self.assertNotLogged( "[test-jail2] Found 192.0.2.2", @@ -775,9 +782,9 @@ class Fail2banServerTest(Fail2banClientServerBase): "restart", "test-jail2") self.assertTrue( Utils.wait_for(lambda: \ - self._is_logged("Jail 'test-jail2' started") and - self._is_logged("[test-jail2] Restore Ban 192.0.2.4") and - self._is_logged("[test-jail2] Restore Ban 192.0.2.8") + self._is_logged("Reload finished.") and + self._is_logged("Restore Ban") and + self._is_logged("2 ticket(s) in 'test-jail2") , MID_WAITTIME)) # stop/start and unban/restore ban: self.assertLogged( @@ -794,8 +801,10 @@ class Fail2banServerTest(Fail2banClientServerBase): self.execSuccess(startparams, "restart", "--unban", "test-jail2") self.assertTrue( - Utils.wait_for(lambda: self._is_logged("Jail 'test-jail2' started"), - MID_WAITTIME)) + Utils.wait_for(lambda: \ + self._is_logged("Reload finished.") and + self._is_logged("Jail 'test-jail2' started") + , MID_WAITTIME)) self.assertLogged( "Jail 'test-jail2' stopped", "Jail 'test-jail2' started", @@ -849,16 +858,17 @@ class Fail2banServerTest(Fail2banClientServerBase): )) if DefLogSys.level < logging.DEBUG: # if HEAVYDEBUG _out_file(test1log) - # test "failure" regexp still available: self.assertTrue( Utils.wait_for(lambda: \ - self._is_logged("[test-jail1] 192.0.2.1 already banned") and - self._is_logged("[test-jail1] Ban 192.0.2.6") + self._is_logged("6 ticket(s) in 'test-jail1") and + self._is_logged("[test-jail1] 192.0.2.1 already banned") , MID_WAITTIME)) + # test "failure" regexp still available: self.assertLogged( "[test-jail1] Found 192.0.2.1", - "[test-jail1] Found 192.0.2.6", all=True - ) + "[test-jail1] Found 192.0.2.6", + "[test-jail1] 192.0.2.1 already banned", + "[test-jail1] Ban 192.0.2.6", all=True) # test "error" regexp no more available: self.assertNotLogged("[test-jail1] Found 192.0.2.5") diff --git a/man/fail2ban-client.1 b/man/fail2ban-client.1 index 0da5fb02..33bce652 100644 --- a/man/fail2ban-client.1 +++ b/man/fail2ban-client.1 @@ -1,12 +1,12 @@ -.\" DO NOT MODIFY THIS FILE! It was generated by help2man 1.44.1. -.TH FAIL2BAN-CLIENT "1" "July 2016" "fail2ban-client v0.10.0a1" "User Commands" +.\" DO NOT MODIFY THIS FILE! It was generated by help2man 1.47.3. +.TH FAIL2BAN-CLIENT "1" "September 2016" "fail2ban-client v0.10.0a2" "User Commands" .SH NAME fail2ban-client \- configure and control the server .SH SYNOPSIS .B fail2ban-client -[\fIOPTIONS\fR] \fI\fR +[\fI\,OPTIONS\/\fR] \fI\,\/\fR .SH DESCRIPTION -Fail2Ban v0.10.0a1 reads log file that contains password failure report +Fail2Ban v0.10.0a2 reads log file that contains password failure report and bans the corresponding IP addresses using firewall rules. .SH OPTIONS .TP @@ -68,17 +68,36 @@ starts the server and the jails \fBrestart\fR restarts the server .TP -\fBreload\fR -reloads the configuration without -restart +\fBrestart [\-\-unban] [\-\-if\-exists] \fR +restarts the jail (alias +for 'reload \fB\-\-restart\fR ... ') .TP -\fBreload \fR -reloads the jail +\fBreload [\-\-restart] [\-\-unban] [\-\-all]\fR +reloads the configuration without +restarting of the server, the +option '\-\-restart' activates +completely restarting of affected +jails, thereby can unban IP +addresses (if option '\-\-unban' +specified) +.TP +\fBreload [\-\-restart] [\-\-unban] [\-\-if\-exists] \fR +reloads the jail , or +restarts it (if option '\-\-restart' +specified) .TP \fBstop\fR stops all jails and terminate the server .TP +\fBunban \fB\-\-all\fR\fR +unbans all IP addresses (in all +jails and database) +.TP +\fBunban ... \fR +unbans (in all jails and +database) +.TP \fBstatus\fR gets the current status of the server @@ -248,9 +267,8 @@ for \fBset maxlines \fR sets the number of to buffer for regex search for -.IP -set addaction [ ] -.IP +.TP +\fBset addaction [ ]\fR adds a new action named for . Optionally for a Python based action, a and @@ -262,45 +280,38 @@ removes the action from .IP COMMAND ACTION CONFIGURATION -.IP -set action actionstart -.IP +.TP +\fBset action actionstart \fR sets the start command of the action for -.IP -set action actionstop sets the stop command of the -.IP +.TP +\fBset action actionstop sets the stop command of the\fR action for -.IP -set action actioncheck -.IP +.TP +\fBset action actioncheck \fR sets the check command of the action for .TP \fBset action actionban \fR sets the ban command of the action for -.IP -set action actionunban -.IP +.TP +\fBset action actionunban \fR sets the unban command of the action for -.IP -set action timeout -.IP +.TP +\fBset action timeout \fR sets as the command timeout in seconds for the action for .IP GENERAL ACTION CONFIGURATION -.IP -set action -.IP +.TP +\fBset action \fR sets the of for the action for -.IP -set action [ ] -.IP +.TP +\fBset action [ ]\fR calls the with for the action for diff --git a/man/fail2ban-regex.1 b/man/fail2ban-regex.1 index f954cb3a..342d18f7 100644 --- a/man/fail2ban-regex.1 +++ b/man/fail2ban-regex.1 @@ -1,10 +1,10 @@ -.\" DO NOT MODIFY THIS FILE! It was generated by help2man 1.44.1. -.TH FAIL2BAN-REGEX "1" "July 2016" "fail2ban-regex 0.10.0a1" "User Commands" +.\" DO NOT MODIFY THIS FILE! It was generated by help2man 1.47.3. +.TH FAIL2BAN-REGEX "1" "September 2016" "fail2ban-regex 0.10.0a2" "User Commands" .SH NAME fail2ban-regex \- test Fail2ban "failregex" option .SH SYNOPSIS .B fail2ban-regex -[\fIOPTIONS\fR] \fI \fR[\fIIGNOREREGEX\fR] +[\fI\,OPTIONS\/\fR] \fI\, \/\fR[\fI\,IGNOREREGEX\/\fR] .SH DESCRIPTION Fail2Ban reads log file that contains password failure report and bans the corresponding IP addresses using firewall rules. @@ -16,7 +16,7 @@ string a string representing a log line .TP filename -path to a log file (\fI/var/log/auth.log\fP) +path to a log file (\fI\,/var/log/auth.log\/\fP) .TP "systemd\-journal" search systemd journal (systemd\-python required) @@ -42,23 +42,23 @@ show program's version number and exit \fB\-h\fR, \fB\-\-help\fR show this help message and exit .TP -\fB\-d\fR DATEPATTERN, \fB\-\-datepattern\fR=\fIDATEPATTERN\fR +\fB\-d\fR DATEPATTERN, \fB\-\-datepattern\fR=\fI\,DATEPATTERN\/\fR set custom pattern used to match date/times .TP -\fB\-e\fR ENCODING, \fB\-\-encoding\fR=\fIENCODING\fR +\fB\-e\fR ENCODING, \fB\-\-encoding\fR=\fI\,ENCODING\/\fR File encoding. Default: system locale .TP \fB\-r\fR, \fB\-\-raw\fR Raw hosts, don't resolve dns .TP -\fB\-L\fR MAXLINES, \fB\-\-maxlines\fR=\fIMAXLINES\fR +\fB\-L\fR MAXLINES, \fB\-\-maxlines\fR=\fI\,MAXLINES\/\fR maxlines for multi\-line regex .TP -\fB\-m\fR JOURNALMATCH, \fB\-\-journalmatch\fR=\fIJOURNALMATCH\fR +\fB\-m\fR JOURNALMATCH, \fB\-\-journalmatch\fR=\fI\,JOURNALMATCH\/\fR journalctl style matches overriding filter file. "systemd\-journal" only .TP -\fB\-l\fR LOG_LEVEL, \fB\-\-log\-level\fR=\fILOG_LEVEL\fR +\fB\-l\fR LOG_LEVEL, \fB\-\-log\-level\fR=\fI\,LOG_LEVEL\/\fR Log level for the Fail2Ban logger to use .TP \fB\-v\fR, \fB\-\-verbose\fR diff --git a/man/fail2ban-server.1 b/man/fail2ban-server.1 index 3b970024..de8ba6a4 100644 --- a/man/fail2ban-server.1 +++ b/man/fail2ban-server.1 @@ -1,12 +1,12 @@ -.\" DO NOT MODIFY THIS FILE! It was generated by help2man 1.44.1. -.TH FAIL2BAN-SERVER "1" "July 2016" "fail2ban-server v0.10.0a1" "User Commands" +.\" DO NOT MODIFY THIS FILE! It was generated by help2man 1.47.3. +.TH FAIL2BAN-SERVER "1" "September 2016" "fail2ban-server v0.10.0a2" "User Commands" .SH NAME fail2ban-server \- start the server .SH SYNOPSIS .B fail2ban-server -[\fIOPTIONS\fR] +[\fI\,OPTIONS\/\fR] .SH DESCRIPTION -Fail2Ban v0.10.0a1 reads log file that contains password failure report +Fail2Ban v0.10.0a2 reads log file that contains password failure report and bans the corresponding IP addresses using firewall rules. .SH OPTIONS .TP diff --git a/man/fail2ban-testcases.1 b/man/fail2ban-testcases.1 index 9089d1ed..26dbae96 100644 --- a/man/fail2ban-testcases.1 +++ b/man/fail2ban-testcases.1 @@ -1,10 +1,10 @@ -.\" DO NOT MODIFY THIS FILE! It was generated by help2man 1.44.1. -.TH FAIL2BAN-TESTCASES "1" "July 2016" "fail2ban-testcases 0.10.0a1" "User Commands" +.\" DO NOT MODIFY THIS FILE! It was generated by help2man 1.47.3. +.TH FAIL2BAN-TESTCASES "1" "September 2016" "fail2ban-testcases 0.10.0a2" "User Commands" .SH NAME fail2ban-testcases \- run Fail2Ban unit-tests .SH SYNOPSIS .B fail2ban-testcases -[\fIOPTIONS\fR] [\fIregexps\fR] +[\fI\,OPTIONS\/\fR] [\fI\,regexps\/\fR] .SH DESCRIPTION Script to run Fail2Ban tests battery .SH OPTIONS @@ -15,9 +15,15 @@ show program's version number and exit \fB\-h\fR, \fB\-\-help\fR show this help message and exit .TP -\fB\-l\fR LOG_LEVEL, \fB\-\-log\-level\fR=\fILOG_LEVEL\fR +\fB\-l\fR LOG_LEVEL, \fB\-\-log\-level\fR=\fI\,LOG_LEVEL\/\fR Log level for the logger to use during running tests .TP +\fB\-v\fR VERBOSITY, \fB\-\-verbosity\fR=\fI\,VERBOSITY\/\fR +Set numerical level of verbosity (0..4) +.TP +\fB\-\-log\-direct\fR +Prevent lazy logging inside tests +.TP \fB\-n\fR, \fB\-\-no\-network\fR Do not run tests that require the network .TP From d1ef33cc45e411b4bdf44b1a048dd5e5968c2661 Mon Sep 17 00:00:00 2001 From: sebres Date: Thu, 8 Sep 2016 19:45:47 +0200 Subject: [PATCH 07/27] New command action parameter `actionrepair` - command executed in order to restore sane environment in error case of `actioncheck`. # [WARNING] TODO: be sure all banactions get a repair command, because otherwise stop/start will theoretically remove all the bans, but the tickets are still in BanManager, so in case of new failures it will not be banned, because "already banned" will happen. --- fail2ban/client/actionreader.py | 1 + fail2ban/server/action.py | 44 ++++++++++++++++++++++++-------- fail2ban/tests/actiontestcase.py | 23 +++++++++++++++++ 3 files changed, 57 insertions(+), 11 deletions(-) diff --git a/fail2ban/client/actionreader.py b/fail2ban/client/actionreader.py index 698360ac..2e02c4aa 100644 --- a/fail2ban/client/actionreader.py +++ b/fail2ban/client/actionreader.py @@ -39,6 +39,7 @@ class ActionReader(DefinitionInitConfigReader): "actionstart": ["string", None], "actionstop": ["string", None], "actioncheck": ["string", None], + "actionrepair": ["string", None], "actionban": ["string", None], "actionunban": ["string", None], } diff --git a/fail2ban/server/action.py b/fail2ban/server/action.py index 702ad397..9f539e2c 100644 --- a/fail2ban/server/action.py +++ b/fail2ban/server/action.py @@ -200,6 +200,8 @@ class CommandAction(ActionBase): Attributes ---------- actionban + actioncheck + actionrepair actionstart actionstop actionunban @@ -217,6 +219,8 @@ class CommandAction(ActionBase): actionunban = '' ## Command executed in order to check requirements. actioncheck = '' + ## Command executed in order to restore sane environment in error case. + actionrepair = '' ## Command executed in order to stop the system. actionstop = '' @@ -271,16 +275,18 @@ class CommandAction(ActionBase): and executes the resulting command. """ # check valid tags in properties (raises ValueError if self recursion, etc.): + res = True try: # common (resp. ipv4): startCmd = self.replaceTag('', self._properties, conditional='family=inet4', cache=self.__substCache) - res = self.executeCmd(startCmd, self.timeout) + if startCmd: + res &= self.executeCmd(startCmd, self.timeout) # start ipv6 actions if available: if allowed_ipv6: startCmd6 = self.replaceTag('', self._properties, conditional='family=inet6', cache=self.__substCache) - if startCmd6 != startCmd: + if startCmd6 and startCmd6 != startCmd: res &= self.executeCmd(startCmd6, self.timeout) if not res: raise RuntimeError("Error starting action %s/%s" % (self._jail, self._name,)) @@ -323,15 +329,17 @@ class CommandAction(ActionBase): Replaces the tags in the action command with actions properties and executes the resulting command. """ + res = True # common (resp. ipv4): stopCmd = self.replaceTag('', self._properties, conditional='family=inet4', cache=self.__substCache) - res = self.executeCmd(stopCmd, self.timeout) + if stopCmd: + res &= self.executeCmd(stopCmd, self.timeout) # ipv6 actions if available: if allowed_ipv6: stopCmd6 = self.replaceTag('', self._properties, conditional='family=inet6', cache=self.__substCache) - if stopCmd6 != stopCmd: + if stopCmd6 and stopCmd6 != stopCmd: res &= self.executeCmd(stopCmd6, self.timeout) if not res: raise RuntimeError("Error stopping action") @@ -520,14 +528,28 @@ class CommandAction(ActionBase): checkCmd = self.replaceTag('', self._properties, conditional=conditional, cache=self.__substCache) - if not self.executeCmd(checkCmd, self.timeout): - self._logSys.error( - "Invariant check failed. Trying to restore a sane environment") - self.stop() - self.start() + if checkCmd: if not self.executeCmd(checkCmd, self.timeout): - self._logSys.critical("Unable to restore environment") - return False + self._logSys.error( + "Invariant check failed. Trying to restore a sane environment") + # try to find repair command, if exists - exec it: + repairCmd = self.replaceTag('', self._properties, + conditional=conditional, cache=self.__substCache) + if repairCmd: + if not self.executeCmd(repairCmd, self.timeout): + self._logSys.critical("Unable to restore environment") + return False + else: + # no repair command, try to restart action... + # [WARNING] TODO: be sure all banactions get a repair command, because + # otherwise stop/start will theoretically remove all the bans, + # but the tickets are still in BanManager, so in case of new failures + # it will not be banned, because "already banned" will happen. + self.stop() + self.start() + if not self.executeCmd(checkCmd, self.timeout): + self._logSys.critical("Unable to restore environment") + return False # Replace static fields realCmd = self.replaceTag(cmd, self._properties, diff --git a/fail2ban/tests/actiontestcase.py b/fail2ban/tests/actiontestcase.py index 57c4856a..166450bb 100644 --- a/fail2ban/tests/actiontestcase.py +++ b/fail2ban/tests/actiontestcase.py @@ -277,6 +277,24 @@ class CommandActionTest(LogCaptureTestCase): self.assertRaises(RuntimeError, self.__action.ban, {'ip': None}) self.assertLogged('Unable to restore environment') + def testExecuteActionCheckRepairEnvironment(self): + self.__action.actionstart = "" + self.__action.actionstop = "" + self.__action.actionban = "rm /tmp/fail2ban.test" + self.__action.actioncheck = "[ -e /tmp/fail2ban.test ]" + self.__action.actionrepair = "echo 'repair ...'; touch /tmp/fail2ban.test" + # 1st time with success repair: + self.__action.ban({'ip': None}) + self.assertLogged("Invariant check failed. Trying", "echo 'repair ...'", all=True) + self.pruneLog() + # 2nd time failed (not really repaired): + self.__action.actionrepair = "echo 'repair ...'" + self.assertRaises(RuntimeError, self.__action.ban, {'ip': None}) + self.assertLogged( + "Invariant check failed. Trying", + "echo 'repair ...'", + "Unable to restore environment", all=True) + def testExecuteActionChangeCtags(self): self.assertRaises(AttributeError, getattr, self.__action, "ROST") self.__action.ROST = "192.0.2.0" @@ -294,7 +312,12 @@ class CommandActionTest(LogCaptureTestCase): def testExecuteActionStartEmpty(self): self.__action.actionstart = "" self.__action.start() + self.assertTrue(self.__action.executeCmd("")) self.assertLogged('Nothing to do') + self.pruneLog() + self.assertTrue(self.__action._processCmd("")) + self.assertLogged('Nothing to do') + self.pruneLog() def testExecuteIncorrectCmd(self): CommandAction.executeCmd('/bin/ls >/dev/null\nbogusXXX now 2>/dev/null') From 4fb511294e01d33e934c32b7d458088e19d42343 Mon Sep 17 00:00:00 2001 From: sebres Date: Thu, 8 Sep 2016 23:56:32 +0200 Subject: [PATCH 08/27] temp commit: reload now supported actions and action reloading (parameters, unban obsolete removed actions, etc.) --- fail2ban/client/actionreader.py | 1 + fail2ban/server/action.py | 88 +++++++++++++--------- fail2ban/server/actions.py | 96 ++++++++++++++++++------ fail2ban/server/banmanager.py | 9 +++ fail2ban/server/database.py | 12 ++- fail2ban/server/filter.py | 3 - fail2ban/server/server.py | 6 +- fail2ban/tests/fail2banclienttestcase.py | 27 ++++++- 8 files changed, 171 insertions(+), 71 deletions(-) diff --git a/fail2ban/client/actionreader.py b/fail2ban/client/actionreader.py index 2e02c4aa..e5025fa3 100644 --- a/fail2ban/client/actionreader.py +++ b/fail2ban/client/actionreader.py @@ -38,6 +38,7 @@ class ActionReader(DefinitionInitConfigReader): _configOpts = { "actionstart": ["string", None], "actionstop": ["string", None], + "actionreload": ["string", None], "actioncheck": ["string", None], "actionrepair": ["string", None], "actionban": ["string", None], diff --git a/fail2ban/server/action.py b/fail2ban/server/action.py index 9f539e2c..976adb20 100644 --- a/fail2ban/server/action.py +++ b/fail2ban/server/action.py @@ -201,6 +201,7 @@ class CommandAction(ActionBase): ---------- actionban actioncheck + actionreload actionrepair actionstart actionstop @@ -210,24 +211,35 @@ class CommandAction(ActionBase): _escapedTags = set(('matches', 'ipmatches', 'ipjailmatches')) - timeout = 60 - ## Command executed in order to initialize the system. - actionstart = '' - ## Command executed when an IP address gets banned. - actionban = '' - ## Command executed when an IP address gets removed. - actionunban = '' - ## Command executed in order to check requirements. - actioncheck = '' - ## Command executed in order to restore sane environment in error case. - actionrepair = '' - ## Command executed in order to stop the system. - actionstop = '' + def clearAllParams(self): + """ Clear all lists/dicts parameters (used by reloading) + """ + self.__init = 1 + try: + self.timeout = 60 + ## Command executed in order to initialize the system. + self.actionstart = '' + ## Command executed when an IP address gets banned. + self.actionban = '' + ## Command executed when an IP address gets removed. + self.actionunban = '' + ## Command executed in order to check requirements. + self.actioncheck = '' + ## Command executed in order to restore sane environment in error case. + self.actionrepair = '' + ## Command executed in order to stop the system. + self.actionstop = '' + ## Command executed in case of reloading action. + self.actionreload = '' + finally: + self.__init = 0 def __init__(self, jail, name): super(CommandAction, self).__init__(jail, name) + self.__init = 1 self.__properties = None self.__substCache = {} + self.clearAllParams() self._logSys.debug("Created %s" % self.__class__) @classmethod @@ -235,7 +247,7 @@ class CommandAction(ActionBase): return NotImplemented # Standard checks def __setattr__(self, name, value): - if not name.startswith('_') and not callable(value): + if not name.startswith('_') and not self.__init and not callable(value): # special case for some pasrameters: if name in ('timeout', 'bantime'): value = str(MyTime.str2seconds(value)) @@ -268,8 +280,8 @@ class CommandAction(ActionBase): def _substCache(self): return self.__substCache - def start(self): - """Executes the "actionstart" command. + def _executeOperation(self, tag, operation): + """Executes the operation commands (like "actionstart", "actionstop", etc). Replace the tags in the action command with actions properties and executes the resulting command. @@ -278,20 +290,28 @@ class CommandAction(ActionBase): res = True try: # common (resp. ipv4): - startCmd = self.replaceTag('', self._properties, + startCmd = self.replaceTag(tag, self._properties, conditional='family=inet4', cache=self.__substCache) if startCmd: res &= self.executeCmd(startCmd, self.timeout) # start ipv6 actions if available: if allowed_ipv6: - startCmd6 = self.replaceTag('', self._properties, + startCmd6 = self.replaceTag(tag, self._properties, conditional='family=inet6', cache=self.__substCache) if startCmd6 and startCmd6 != startCmd: res &= self.executeCmd(startCmd6, self.timeout) if not res: - raise RuntimeError("Error starting action %s/%s" % (self._jail, self._name,)) + raise RuntimeError("Error %s action %s/%s" % (operation, self._jail, self._name,)) except ValueError as e: - raise RuntimeError("Error starting action %s/%s: %r" % (self._jail, self._name, e)) + raise RuntimeError("Error %s action %s/%s: %r" % (operation, self._jail, self._name, e)) + + def start(self): + """Executes the "actionstart" command. + + Replace the tags in the action command with actions properties + and executes the resulting command. + """ + return self._executeOperation('', 'starting') def ban(self, aInfo): """Executes the "actionban" command. @@ -329,20 +349,20 @@ class CommandAction(ActionBase): Replaces the tags in the action command with actions properties and executes the resulting command. """ - res = True - # common (resp. ipv4): - stopCmd = self.replaceTag('', self._properties, - conditional='family=inet4', cache=self.__substCache) - if stopCmd: - res &= self.executeCmd(stopCmd, self.timeout) - # ipv6 actions if available: - if allowed_ipv6: - stopCmd6 = self.replaceTag('', self._properties, - conditional='family=inet6', cache=self.__substCache) - if stopCmd6 and stopCmd6 != stopCmd: - res &= self.executeCmd(stopCmd6, self.timeout) - if not res: - raise RuntimeError("Error stopping action") + return self._executeOperation('', 'stopping') + + def reload(self, **kwargs): + """Executes the "actionreload" command. + + Parameters + ---------- + kwargs : dict + Currently unused, because CommandAction do not support initOpts + + Replaces the tags in the action command with actions properties + and executes the resulting command. + """ + return self._executeOperation('', 'reloading') @classmethod def substituteRecursiveTags(cls, inptags, conditional=''): diff --git a/fail2ban/server/actions.py b/fail2ban/server/actions.py index 244d1e68..09b6823d 100644 --- a/fail2ban/server/actions.py +++ b/fail2ban/server/actions.py @@ -36,7 +36,7 @@ from collections import Mapping try: from collections import OrderedDict except ImportError: - OrderedDict = None + OrderedDict = dict from .banmanager import BanManager from .jailthread import JailThread @@ -81,14 +81,11 @@ class Actions(JailThread, Mapping): JailThread.__init__(self) ## The jail which contains this action. self._jail = jail - if OrderedDict is not None: - self._actions = OrderedDict() - else: - self._actions = dict() + self._actions = OrderedDict() ## The ban manager. self.__banManager = BanManager() - def add(self, name, pythonModule=None, initOpts=None): + def add(self, name, pythonModule=None, initOpts=None, reload=False): """Adds a new action. Add a new action if not already present, defaulting to standard @@ -116,7 +113,17 @@ class Actions(JailThread, Mapping): """ # Check is action name already exists if name in self._actions: - raise ValueError("Action %s already exists" % name) + if not reload: + raise ValueError("Action %s already exists" % name) + # don't create new action if reload supported: + action = self._actions[name] + if hasattr(action, 'reload'): + # don't execute reload right now, reload after all parameters are actualized + if hasattr(action, 'clearAllParams'): + action.clearAllParams() + self._reload_actions[name] = initOpts + return + ## Create new action: if pythonModule is None: action = CommandAction(self._jail, name) else: @@ -138,6 +145,27 @@ class Actions(JailThread, Mapping): action = customActionModule.Action(self._jail, name, **initOpts) self._actions[name] = action + def reload(self, begin=True): + """ Begin or end of reloading resp. refreshing of all parameters + """ + if begin: + self._reload_actions = dict() + else: + if hasattr(self, '_reload_actions'): + # reload actions after all parameters set via stream: + for name, initOpts in self._reload_actions.iteritems(): + if name in self._actions: + self._actions[name].reload(**initOpts if initOpts else {}) + # remove obsolete actions (untouched by reload process): + delacts = OrderedDict((name, action) for name, action in self._actions.iteritems() + if name not in self._reload_actions) + if len(delacts): + # unban all tickets using remove action only: + self.__flushBan(db=False, actions=delacts) + # stop and remove it: + self.stopActions(actions=delacts) + delattr(self, '_reload_actions') + def __getitem__(self, name): try: return self._actions[name] @@ -215,6 +243,24 @@ class Actions(JailThread, Mapping): return 1 + def stopActions(self, actions=None): + """Stops the actions in reverse sequence (optionally filtered) + """ + if actions is None: + actions = self._actions + revactions = actions.items() + revactions.reverse() + for name, action in revactions: + try: + action.stop() + except Exception as e: + logSys.error("Failed to stop jail '%s' action '%s': %s", + self._jail.name, name, e, + exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) + del self._actions[name] + logSys.debug("%s: action %s terminated", self._jail.name, name) + + def run(self): """Main loop for Threading. @@ -239,18 +285,9 @@ class Actions(JailThread, Mapping): continue if not Utils.wait_for(self.__checkBan, self.sleeptime): self.__checkUnBan() + self.__flushBan() - - actions = self._actions.items() - actions.reverse() - for name, action in actions: - try: - action.stop() - except Exception as e: - logSys.error("Failed to stop jail '%s' action '%s': %s", - self._jail.name, name, e, - exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) - logSys.debug(self._jail.name + ": action terminated") + self.stopActions() return True def __getBansMerged(self, mi, overalljails=False): @@ -355,26 +392,33 @@ class Actions(JailThread, Mapping): cnt, self.__banManager.size(), self._jail.name) return cnt - def __flushBan(self, db=False): + def __flushBan(self, db=False, actions=None): """Flush the ban list. Unban all IP address which are still in the banning list. + + If actions specified, don't flush list - just execute unban for + given actions (reload, obsolete resp. removed actions). """ - logSys.debug("Flush ban list") - lst = self.__banManager.flushBanList() + if actions is None: + logSys.debug("Flush ban list") + lst = self.__banManager.flushBanList() + else: + lst = iter(self.__banManager) + cnt = 0 for ticket in lst: # delete ip from database also: if db and self._jail.database is not None: ip = str(ticket.getIP()) self._jail.database.delBan(self._jail, ip) # unban ip: - self.__unBan(ticket) - cnt = len(lst) + self.__unBan(ticket, actions=actions) + cnt += 1 logSys.debug("Unbanned %s, %s ticket(s) in %r", cnt, self.__banManager.size(), self._jail.name) return cnt - def __unBan(self, ticket): + def __unBan(self, ticket, actions=None): """Unbans host corresponding to the ticket. Executes the actions in order to unban the host given in the @@ -385,13 +429,15 @@ class Actions(JailThread, Mapping): ticket : FailTicket Ticket of failures of which to unban """ + if actions is None: + actions = self._actions aInfo = dict() aInfo["ip"] = ticket.getIP() aInfo["failures"] = ticket.getAttempt() aInfo["time"] = ticket.getTime() aInfo["matches"] = "".join(ticket.getMatches()) logSys.notice("[%s] Unban %s" % (self._jail.name, aInfo["ip"])) - for name, action in self._actions.iteritems(): + for name, action in actions.iteritems(): try: action.unban(aInfo.copy()) except Exception as e: diff --git a/fail2ban/server/banmanager.py b/fail2ban/server/banmanager.py index e0a9e5ca..41e202ef 100644 --- a/fail2ban/server/banmanager.py +++ b/fail2ban/server/banmanager.py @@ -106,6 +106,15 @@ class BanManager: with self.__lock: return self.__banList.keys() + ## + # Returns a iterator to ban list (used in reload, so idle). + # + # @return ban list iterator + + def __iter__(self): + with self.__lock: + return self.__banList.itervalues() + ## # Returns normalized value # diff --git a/fail2ban/server/database.py b/fail2ban/server/database.py index fc544be4..53db84a9 100644 --- a/fail2ban/server/database.py +++ b/fail2ban/server/database.py @@ -604,16 +604,14 @@ class Fail2BanDb(object): results = list(self._getCurrentBans(jail=jail, ip=ip, forbantime=forbantime, fromtime=fromtime)) if results: - matches = [] - failures = 0 for banip, timeofban, data in results: - #TODO: Implement data parts once arbitrary match keys completed - ticket = FailTicket(banip, timeofban, matches) - ticket.setAttempt(failures) matches = [] failures = 0 - matches.extend(data['matches']) - failures += data['failures'] + if isinstance(data['matches'], list): + matches.extend(data['matches']) + if data['failures']: + failures += data['failures'] + ticket = FailTicket(banip, timeofban, matches) ticket.setAttempt(failures) tickets.append(ticket) diff --git a/fail2ban/server/filter.py b/fail2ban/server/filter.py index 1c466c01..6b0599f5 100644 --- a/fail2ban/server/filter.py +++ b/fail2ban/server/filter.py @@ -117,14 +117,11 @@ class Filter(JailThread): self._reload_logs = dict((k, 1) for k in self.getLogPaths()) else: if hasattr(self, '_reload_logs'): - dellogs = dict() # if it was not reloaded - remove obsolete log file: for path in self._reload_logs: self.delLogPath(path) delattr(self, '_reload_logs') - - ## # Add a regular expression which matches the failure. # diff --git a/fail2ban/server/server.py b/fail2ban/server/server.py index 041b0983..fc91ca73 100644 --- a/fail2ban/server/server.py +++ b/fail2ban/server/server.py @@ -267,6 +267,7 @@ class Server: jail.idle = True self.__reload_state[jn] = jail jail.filter.reload(begin=True) + jail.actions.reload(begin=True) pass else: # end reload, all affected (or new) jails have already all new parameters (via stream) and (re)started: @@ -280,6 +281,7 @@ class Server: else: # commit (reload was finished): jail.filter.reload(begin=False) + jail.actions.reload(begin=False) for jn in deljails: self.delJail(jn) self.__reload_state = {} @@ -416,7 +418,9 @@ class Server: # Action def addAction(self, name, value, *args): - self.__jails[name].actions.add(value, *args) + ## create (or reload) jail action: + self.__jails[name].actions.add(value, *args, + reload=name in self.__reload_state) def getActions(self, name): return self.__jails[name].actions diff --git a/fail2ban/tests/fail2banclienttestcase.py b/fail2ban/tests/fail2banclienttestcase.py index 394a000f..d818e252 100644 --- a/fail2ban/tests/fail2banclienttestcase.py +++ b/fail2ban/tests/fail2banclienttestcase.py @@ -677,6 +677,20 @@ class Fail2banServerTest(Fail2banClientServerBase): test2log = pjoin(tmp, "test2.log") test3log = pjoin(tmp, "test3.log") + os.mkdir(pjoin(cfg, "action.d")) + def _write_action_cfg(actname="test-action1"): + fn = pjoin(cfg, "action.d", "%s.conf" % actname) + _write_file(fn, "w", + "[Definition]", + "actionstart = echo '[] %s: ** start'" % actname, + "actionstop = echo '[] %s: -- unban '" % actname, + "actionreload = echo '[] %s: ** reload'" % actname, + "actionban = echo '[] %s: ++ ban '" % actname, + "actionunban = echo '[] %s: // stop'" % actname, + ) + if DefLogSys.level < logging.DEBUG: # if HEAVYDEBUG + _out_file(fn) + def _write_jail_cfg(enabled=[1, 2]): _write_file(pjoin(cfg, "jail.conf"), "w", "[INCLUDES]", "", @@ -686,7 +700,9 @@ class Fail2banServerTest(Fail2banClientServerBase): "findtime = 10m", "failregex = ^\s*failure (401|403) from ", "", - "[test-jail1]", "backend = polling", "filter =", "action =", + "[test-jail1]", "backend = polling", "filter =", + "action = test-action1[name='%(__name__)s']", + " test-action2[name='%(__name__)s']", "logpath = " + test1log, " " + test2log if 2 in enabled else "", " " + test3log if 2 in enabled else "", @@ -701,6 +717,10 @@ class Fail2banServerTest(Fail2banClientServerBase): if DefLogSys.level < logging.DEBUG: # if HEAVYDEBUG _out_file(pjoin(cfg, "jail.conf")) + # create default test actions: + _write_action_cfg(actname="test-action1") + _write_action_cfg(actname="test-action2") + _write_jail_cfg(enabled=[1]) _write_file(test1log, "w", *((str(int(MyTime.time())) + " failure 401 from 192.0.2.1: test 1",) * 3)) _write_file(test2log, "w") @@ -737,6 +757,11 @@ class Fail2banServerTest(Fail2banClientServerBase): self.assertLogged( "Added logfile: %r" % test2log, "Added logfile: %r" % test3log, all=True) + # test actions reloaded: + self.assertLogged( + "echo '[test-jail1] test-action1: ** reload' -- returned successfully", + "echo '[test-jail1] test-action2: ** reload' -- returned successfully", all=True) + # test 1 new jail: self.assertLogged( "Creating new jail 'test-jail2'", From 8c4eebc3e315dd6b7602d8fbebf900947cf3e8f2 Mon Sep 17 00:00:00 2001 From: sebres Date: Fri, 9 Sep 2016 00:39:48 +0200 Subject: [PATCH 09/27] reload actions amend, code review and test cases extended for update/start/stop of actions by reloading --- fail2ban/server/actions.py | 10 ++- fail2ban/server/asyncserver.py | 5 +- fail2ban/server/database.py | 16 ++--- fail2ban/server/server.py | 6 ++ fail2ban/server/ticket.py | 7 +- fail2ban/tests/fail2banclienttestcase.py | 83 ++++++++++++++++++------ 6 files changed, 91 insertions(+), 36 deletions(-) diff --git a/fail2ban/server/actions.py b/fail2ban/server/actions.py index 09b6823d..5ac7b9a9 100644 --- a/fail2ban/server/actions.py +++ b/fail2ban/server/actions.py @@ -430,15 +430,19 @@ class Actions(JailThread, Mapping): Ticket of failures of which to unban """ if actions is None: - actions = self._actions + unbactions = self._actions + else: + unbactions = actions aInfo = dict() aInfo["ip"] = ticket.getIP() aInfo["failures"] = ticket.getAttempt() aInfo["time"] = ticket.getTime() aInfo["matches"] = "".join(ticket.getMatches()) - logSys.notice("[%s] Unban %s" % (self._jail.name, aInfo["ip"])) - for name, action in actions.iteritems(): + if actions is None: + logSys.notice("[%s] Unban %s", self._jail.name, aInfo["ip"]) + for name, action in unbactions.iteritems(): try: + logSys.debug("[%s] action %r: unban %s", self._jail.name, name, aInfo["ip"]) action.unban(aInfo.copy()) except Exception as e: logSys.error( diff --git a/fail2ban/server/asyncserver.py b/fail2ban/server/asyncserver.py index bb237cd7..ffb20503 100644 --- a/fail2ban/server/asyncserver.py +++ b/fail2ban/server/asyncserver.py @@ -199,6 +199,7 @@ class AsyncServer(asyncore.dispatcher): def close(self): + stopflg = False if self.__active: self.__loop = False asyncore.dispatcher.close(self) @@ -206,11 +207,13 @@ class AsyncServer(asyncore.dispatcher): # for the server leaves loop, before remove socket if threading.current_thread() != self.__worker: Utils.wait_for(lambda: not self.__active, 1) + stopflg = True # Remove socket (file) only if it was created: if self.__init and os.path.exists(self.__sock): self._remove_sock() logSys.debug("Removed socket file " + self.__sock) - logSys.debug("Socket shutdown") + if stopflg: + logSys.debug("Socket shutdown") self.__active = False ## diff --git a/fail2ban/server/database.py b/fail2ban/server/database.py index 53db84a9..24445f3d 100644 --- a/fail2ban/server/database.py +++ b/fail2ban/server/database.py @@ -223,6 +223,11 @@ class Fail2BanDb(object): cur.execute("PRAGMA journal_mode = MEMORY") cur.close() + def close(self): + logSys.debug("Close connection to database ...") + self._db.close() + logSys.info("Connection to database closed.") + @property def filename(self): """File name of SQLite3 database file. @@ -605,14 +610,9 @@ class Fail2BanDb(object): if results: for banip, timeofban, data in results: - matches = [] - failures = 0 - if isinstance(data['matches'], list): - matches.extend(data['matches']) - if data['failures']: - failures += data['failures'] - ticket = FailTicket(banip, timeofban, matches) - ticket.setAttempt(failures) + # logSys.debug('restore ticket %r, %r, %r', banip, timeofban, data) + ticket = FailTicket(banip, timeofban, data=data) + # logSys.debug('restored ticket: %r', ticket) tickets.append(ticket) return tickets if ip is None else ticket diff --git a/fail2ban/server/server.py b/fail2ban/server/server.py index fc91ca73..97345331 100644 --- a/fail2ban/server/server.py +++ b/fail2ban/server/server.py @@ -171,6 +171,12 @@ class Server: # Now stop all the jails self.stopAllJail() + # 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 + # Only now shutdown the logging. if self.__logTarget is not None: with self.__loggingLock: diff --git a/fail2ban/server/ticket.py b/fail2ban/server/ticket.py index 4dc6ab88..8ff6a780 100644 --- a/fail2ban/server/ticket.py +++ b/fail2ban/server/ticket.py @@ -51,13 +51,12 @@ class Ticket: self._banCount = 0; self._banTime = None; self._time = time if time is not None else MyTime.time() - self._data = {'matches': [], 'failures': 0} - self._data.update(data) + self._data = {'matches': matches or [], 'failures': 0} + if data is not None: + self._data.update(data) 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__) - else: - self._data['matches'] = matches or [] def __str__(self): return "%s: ip=%s time=%s #attempts=%d matches=%r" % \ diff --git a/fail2ban/tests/fail2banclienttestcase.py b/fail2ban/tests/fail2banclienttestcase.py index d818e252..2804fcd4 100644 --- a/fail2ban/tests/fail2banclienttestcase.py +++ b/fail2ban/tests/fail2banclienttestcase.py @@ -678,20 +678,24 @@ class Fail2banServerTest(Fail2banClientServerBase): test3log = pjoin(tmp, "test3.log") os.mkdir(pjoin(cfg, "action.d")) - def _write_action_cfg(actname="test-action1"): + def _write_action_cfg(actname="test-action1", allow=True, + start="", reload="", ban="", unban="", stop=""): fn = pjoin(cfg, "action.d", "%s.conf" % actname) + if not allow: + os.remove(fn) + return _write_file(fn, "w", "[Definition]", - "actionstart = echo '[] %s: ** start'" % actname, - "actionstop = echo '[] %s: -- unban '" % actname, - "actionreload = echo '[] %s: ** reload'" % actname, - "actionban = echo '[] %s: ++ ban '" % actname, - "actionunban = echo '[] %s: // stop'" % actname, + "actionstart = echo '[] %s: ** start'" % actname, start, + "actionreload = echo '[] %s: .. reload'" % actname, reload, + "actionban = echo '[] %s: ++ ban '" % actname, ban, + "actionunban = echo '[] %s: -- unban '" % actname, unban, + "actionstop = echo '[] %s: __ stop'" % actname, stop, ) - if DefLogSys.level < logging.DEBUG: # if HEAVYDEBUG + if DefLogSys.level <= logging.DEBUG: # if DEBUG _out_file(fn) - def _write_jail_cfg(enabled=[1, 2]): + def _write_jail_cfg(enabled=(1, 2), actions=()): _write_file(pjoin(cfg, "jail.conf"), "w", "[INCLUDES]", "", "[DEFAULT]", "", @@ -701,8 +705,9 @@ class Fail2banServerTest(Fail2banClientServerBase): "failregex = ^\s*failure (401|403) from ", "", "[test-jail1]", "backend = polling", "filter =", - "action = test-action1[name='%(__name__)s']", - " test-action2[name='%(__name__)s']", + "action = ", + " test-action1[name='%(__name__)s']" if 1 in actions else "", + " test-action2[name='%(__name__)s']" if 2 in actions else "", "logpath = " + test1log, " " + test2log if 2 in enabled else "", " " + test3log if 2 in enabled else "", @@ -710,24 +715,25 @@ class Fail2banServerTest(Fail2banClientServerBase): " ^\s*error (401|403) from " if 2 in enabled else "", "enabled = true" if 1 in enabled else "", "", - "[test-jail2]", "backend = polling", "filter =", "action =", + "[test-jail2]", "backend = polling", "filter =", + "action =", "logpath = " + test2log, "enabled = true" if 2 in enabled else "", ) - if DefLogSys.level < logging.DEBUG: # if HEAVYDEBUG + if DefLogSys.level <= logging.DEBUG: # if DEBUG _out_file(pjoin(cfg, "jail.conf")) # create default test actions: _write_action_cfg(actname="test-action1") _write_action_cfg(actname="test-action2") - _write_jail_cfg(enabled=[1]) + _write_jail_cfg(enabled=[1], actions=[1,2]) _write_file(test1log, "w", *((str(int(MyTime.time())) + " failure 401 from 192.0.2.1: test 1",) * 3)) _write_file(test2log, "w") _write_file(test3log, "w") # reload and wait for ban: - self.pruneLog("[test-phase 1]") + self.pruneLog("[test-phase 1a]") if DefLogSys.level < logging.DEBUG: # if HEAVYDEBUG _out_file(test1log) self.execSuccess(startparams, "reload") @@ -738,11 +744,15 @@ class Fail2banServerTest(Fail2banClientServerBase): , MID_WAITTIME)) self.assertLogged("Added logfile: %r" % test1log) self.assertLogged("[test-jail1] Ban 192.0.2.1") + # test actions started: + self.assertLogged( + "stdout: '[test-jail1] test-action1: ** start'", + "stdout: '[test-jail1] test-action2: ** start'", all=True) # enable both jails, 3 logs for jail1, etc... # truncate test-log - we should not find unban/ban again by reload: - self.pruneLog("[test-phase 2a]") - _write_jail_cfg() + self.pruneLog("[test-phase 1b]") + _write_jail_cfg(actions=[1,2]) _write_file(test1log, "w+") if DefLogSys.level < logging.DEBUG: # if HEAVYDEBUG _out_file(test1log) @@ -759,14 +769,47 @@ class Fail2banServerTest(Fail2banClientServerBase): "Added logfile: %r" % test3log, all=True) # test actions reloaded: self.assertLogged( - "echo '[test-jail1] test-action1: ** reload' -- returned successfully", - "echo '[test-jail1] test-action2: ** reload' -- returned successfully", all=True) - + "stdout: '[test-jail1] test-action1: .. reload'", + "stdout: '[test-jail1] test-action2: .. reload'", all=True) # test 1 new jail: self.assertLogged( "Creating new jail 'test-jail2'", "Jail 'test-jail2' started", all=True) - + + # update action1, delete action2 (should be stopped via configuration)... + self.pruneLog("[test-phase 2a]") + _write_jail_cfg(actions=[1]) + _write_action_cfg(actname="test-action1", + start= " echo '[] %s: started.'" % "test-action1", + reload=" echo '[] %s: reloaded.'" % "test-action1", + stop= " echo '[] %s: stopped.'" % "test-action1") + self.execSuccess(startparams, "reload") + self.assertTrue( + Utils.wait_for(lambda: self._is_logged("Reload finished."), MID_WAITTIME)) + # test not unbanned / banned again: + self.assertNotLogged( + "[test-jail1] Unban 192.0.2.1", + "[test-jail1] Ban 192.0.2.1", all=True) + # no new log files: + self.assertNotLogged("Added logfile:") + # test action reloaded (update): + self.assertLogged( + "stdout: '[test-jail1] test-action1: .. reload'", + "stdout: '[test-jail1] test-action1: reloaded.'", all=True) + # test stopped action unbans: + self.assertLogged( + "stdout: '[test-jail1] test-action2: -- unban 192.0.2.1'") + # test action stopped: + self.assertLogged( + "stdout: '[test-jail1] test-action2: __ stop'") + self.assertNotLogged( + "stdout: '[test-jail1] test-action1: -- unban 192.0.2.1'") + + # don't need both actions anymore: + _write_action_cfg(actname="test-action1", allow=False) + _write_action_cfg(actname="test-action2", allow=False) + _write_jail_cfg(actions=[]) + # write new failures: self.pruneLog("[test-phase 2b]") _write_file(test2log, "w+", *( From 4404642fa32d4626500d784e1569a8e94c949833 Mon Sep 17 00:00:00 2001 From: sebres Date: Fri, 9 Sep 2016 10:56:35 +0200 Subject: [PATCH 10/27] pyinotify-backend: stability fix for sporadically errors in multi-threaded environment (without lock) --- fail2ban/server/filterpyinotify.py | 24 ++++++++++++++---------- 1 file changed, 14 insertions(+), 10 deletions(-) diff --git a/fail2ban/server/filterpyinotify.py b/fail2ban/server/filterpyinotify.py index c5b5680b..1e08f250 100644 --- a/fail2ban/server/filterpyinotify.py +++ b/fail2ban/server/filterpyinotify.py @@ -119,14 +119,15 @@ class FilterPyinotify(FileFilter): logSys.debug("Added file watcher for %s", path) def _delFileWatcher(self, path): - wdInt = self.__watches[path] - wd = self.__monitor.rm_watch(wdInt) - if wd[wdInt]: - del self.__watches[path] - logSys.debug("Removed file watcher for %s", path) - return True - else: - return False + try: + wdInt = self.__watches.pop(path) + wd = self.__monitor.rm_watch(wdInt) + if wd[wdInt]: + logSys.debug("Removed file watcher for %s", path) + return True + except KeyError: # pragma: no cover + pass + return False ## # Add a log file path @@ -158,8 +159,11 @@ class FilterPyinotify(FileFilter): if k.startswith(path_dir + pathsep)]): # Remove watches for the directory # since there is no other monitored file under this directory - wdInt = self.__watches.pop(path_dir) - self.__monitor.rm_watch(wdInt) + try: + wdInt = self.__watches.pop(path_dir) + self.__monitor.rm_watch(wdInt) + except KeyError: # pragma: no cover + pass logSys.debug("Removed monitor for the parent directory %s", path_dir) # pyinotify.ProcessEvent default handler: From 2108216d33bc7edbbc5f40c3aaf9eac9e27279eb Mon Sep 17 00:00:00 2001 From: sebres Date: Fri, 9 Sep 2016 16:08:28 +0200 Subject: [PATCH 11/27] file filter-backends: stability fix for sporadically errors - always close file handle, otherwise may be locked (prevent log-rotate, etc.) --- fail2ban/server/filter.py | 75 +++++++++++++++++++-------------------- 1 file changed, 37 insertions(+), 38 deletions(-) diff --git a/fail2ban/server/filter.py b/fail2ban/server/filter.py index 6b0599f5..ab6e7b15 100644 --- a/fail2ban/server/filter.py +++ b/fail2ban/server/filter.py @@ -799,49 +799,48 @@ class FileFilter(Filter): if log is None: logSys.error("Unable to get failures in " + filename) return False - # Try to open log file. + # We should always close log (file), otherwise may be locked (log-rotate, etc.) try: - has_content = log.open() - # see http://python.org/dev/peps/pep-3151/ - except IOError as e: - logSys.error("Unable to open %s" % filename) - logSys.exception(e) - return False - except OSError as e: # pragma: no cover - requires race condition to tigger this - logSys.error("Error opening %s" % filename) - logSys.exception(e) - return False - except Exception as e: # pragma: no cover - Requires implemention error in FileContainer to generate - logSys.error("Internal error in FileContainer open method - please report as a bug to https://github.com/fail2ban/fail2ban/issues") - logSys.exception(e) - return False - - # seek to find time for first usage only (prevent performance decline with polling of big files) - if self.__autoSeek.get(filename): - startTime = self.__autoSeek[filename] - del self.__autoSeek[filename] - # prevent completely read of big files first time (after start of service), - # initial seek to start time using half-interval search algorithm: + # Try to open log file. try: - self.seekToTime(log, startTime) - except Exception as e: # pragma: no cover - logSys.error("Error during seek to start time in \"%s\"", filename) - raise + has_content = log.open() + # see http://python.org/dev/peps/pep-3151/ + except IOError as e: + logSys.error("Unable to open %s" % filename) + logSys.exception(e) + return False + except OSError as e: # pragma: no cover - requires race condition to tigger this + logSys.error("Error opening %s" % filename) + logSys.exception(e) + return False + except Exception as e: # pragma: no cover - Requires implemention error in FileContainer to generate + logSys.error("Internal error in FileContainer open method - please report as a bug to https://github.com/fail2ban/fail2ban/issues") logSys.exception(e) return False - # yoh: has_content is just a bool, so do not expect it to - # change -- loop is exited upon break, and is not entered at - # all if upon container opening that one was empty. If we - # start reading tested to be empty container -- race condition - # might occur leading at least to tests failures. - while has_content: - line = log.readline() - if not line or not self.active: - # The jail reached the bottom or has been stopped - break - self.processLineAndAdd(line) - log.close() + # seek to find time for first usage only (prevent performance decline with polling of big files) + if self.__autoSeek.get(filename): + startTime = self.__autoSeek[filename] + del self.__autoSeek[filename] + # prevent completely read of big files first time (after start of service), + # initial seek to start time using half-interval search algorithm: + try: + self.seekToTime(log, startTime) + except Exception as e: # pragma: no cover + logSys.error("Error during seek to start time in \"%s\"", filename) + raise + logSys.exception(e) + return False + + if has_content: + while not self.idle: + line = log.readline() + if not line or not self.active: + # The jail reached the bottom or has been stopped + break + self.processLineAndAdd(line) + finally: + log.close() db = self.jail.database if db is not None: db.updateLog(self.jail, log) From f6197200a9d250200e0f64fc26fd60c7e556ce5f Mon Sep 17 00:00:00 2001 From: sebres Date: Fri, 9 Sep 2016 16:12:48 +0200 Subject: [PATCH 12/27] introduced new flag "banned" as property, used to recognize the ticket was really banned; get/set restored flag functions rewritten to property "restored" similar to "banned"; several code optimizations and tests extensions; --- fail2ban/server/actions.py | 21 +++++++++++++++++--- fail2ban/server/banmanager.py | 29 ++++++++++++++-------------- fail2ban/server/jail.py | 19 ++++++++++++++---- fail2ban/server/ticket.py | 22 ++++++++++++++++----- fail2ban/tests/banmanagertestcase.py | 17 ++++++++++++---- fail2ban/tests/tickettestcase.py | 18 +++++++++++++++++ 6 files changed, 96 insertions(+), 30 deletions(-) diff --git a/fail2ban/server/actions.py b/fail2ban/server/actions.py index 5ac7b9a9..bc8684b5 100644 --- a/fail2ban/server/actions.py +++ b/fail2ban/server/actions.py @@ -359,9 +359,10 @@ class Actions(JailThread, Mapping): aInfo["ipjailmatches"] = lambda: "\n".join(mi4ip().getMatches()) aInfo["ipfailures"] = lambda: mi4ip(True).getAttempt() aInfo["ipjailfailures"] = lambda: mi4ip().getAttempt() - if self.__banManager.addBanTicket(bTicket): + reason = {} + if self.__banManager.addBanTicket(bTicket, reason=reason): cnt += 1 - logSys.notice("[%s] %sBan %s", self._jail.name, ('' if not bTicket.getRestored() else 'Restore '), ip) + logSys.notice("[%s] %sBan %s", self._jail.name, ('' if not bTicket.restored else 'Restore '), ip) for name, action in self._actions.iteritems(): try: action.ban(aInfo.copy()) @@ -371,8 +372,22 @@ class Actions(JailThread, Mapping): "info '%r': %s", self._jail.name, name, aInfo, e, exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) + # after all actions are processed set banned flag: + bTicket.banned = True else: - logSys.notice("[%s] %s already banned", self._jail.name, ip) + bTicket = reason['ticket'] + # if already banned (otherwise still process some action) + if bTicket.banned: + # compare time of failure occurrence with time ticket was really banned: + diftm = ticket.getTime() - bTicket.getTime() + # log already banned with following level: + # DEBUG - before 3 seconds - certain interval for it, because of possible latency by recognizing in backends, etc. + # NOTICE - before 60 seconds - may still occurre if action are slow, or very high load in backend, + # WARNING - after 60 seconds - very long time, something may be wrong + ll = logging.DEBUG if diftm < 3 \ + else logging.NOTICE if diftm < 60 \ + else logging.WARNING + logSys.log(ll, "[%s] %s already banned", self._jail.name, ip) if cnt: logSys.debug("Banned %s / %s, %s ticket(s) in %r", cnt, self.__banManager.getBanTotal(), self.__banManager.size(), self._jail.name) diff --git a/fail2ban/server/banmanager.py b/fail2ban/server/banmanager.py index 41e202ef..6da5366c 100644 --- a/fail2ban/server/banmanager.py +++ b/fail2ban/server/banmanager.py @@ -256,29 +256,30 @@ class BanManager: # @param ticket the ticket # @return True if the IP address is not in the ban list - def addBanTicket(self, ticket): + def addBanTicket(self, ticket, reason={}): + eob = ticket.getEndOfBanTime(self.__banTime) with self.__lock: # check already banned fid = ticket.getID() oldticket = self.__banList.get(fid) if oldticket: - # if already permanent - btold, told = oldticket.getBanTime(self.__banTime), oldticket.getTime() - if btold == -1: - return False - # if given time is less than already banned time - btnew, tnew = ticket.getBanTime(self.__banTime), ticket.getTime() - if btnew != -1 and tnew + btnew <= told + btold: - return False - # we have longest ban - set new (increment) ban time - oldticket.setTime(tnew) - oldticket.setBanTime(btnew) + reason['ticket'] = oldticket + # if new time for end of ban is larger than already banned end-time: + if eob > oldticket.getEndOfBanTime(self.__banTime): + # we have longest ban - set new (increment) ban time + reason['prolong'] = 1 + btm = ticket.getBanTime(self.__banTime) + # if not permanent: + if btm != -1: + diftm = ticket.getTime() - oldticket.getTime() + if diftm > 0: + btm += diftm + oldticket.setBanTime(btm) return False - # not yet banned - add new + # not yet banned - add new one: self.__banList[fid] = ticket self.__banTotal += 1 # correct next unban time: - eob = ticket.getEndOfBanTime(self.__banTime) if self.__nextUnbanTime > eob: self.__nextUnbanTime = eob return True diff --git a/fail2ban/server/jail.py b/fail2ban/server/jail.py index 7e05a025..e70eaddd 100644 --- a/fail2ban/server/jail.py +++ b/fail2ban/server/jail.py @@ -28,7 +28,7 @@ import Queue from .actions import Actions from ..client.jailreader import JailReader -from ..helpers import getLogger +from ..helpers import getLogger, MyTime # Gets the instance of the logger. logSys = getLogger(__name__) @@ -194,7 +194,7 @@ class Jail(object): Used by filter to add a failure for banning. """ self.__queue.put(ticket) - if not ticket.getRestored() and self.database is not None: + if not ticket.restored and self.database is not None: self.database.addBan(self, ticket) def getFailTicket(self): @@ -203,7 +203,8 @@ class Jail(object): Used by actions to get a failure for banning. """ try: - return self.__queue.get(False) + ticket = self.__queue.get(False) + return ticket except Queue.Empty: return False @@ -217,7 +218,17 @@ class Jail(object): #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) + ticket.restored = True + # correct start time / ban time (by the same end of ban): + btm = ticket.getBanTime(forbantime) + diftm = MyTime.time() - ticket.getTime() + if btm != -1 and diftm > 0: + btm -= diftm + # 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('%s', e, exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) diff --git a/fail2ban/server/ticket.py b/fail2ban/server/ticket.py index 8ff6a780..2f9a88ed 100644 --- a/fail2ban/server/ticket.py +++ b/fail2ban/server/ticket.py @@ -34,9 +34,10 @@ from .mytime import MyTime logSys = getLogger(__name__) -class Ticket: +class Ticket(object): RESTORED = 0x01 + BANNED = 0x08 def __init__(self, ip=None, time=None, matches=None, data={}, ticket=None): """Ticket constructor @@ -135,14 +136,25 @@ class Ticket: def getMatches(self): return self._data.get('matches', []) - def setRestored(self, value): + @property + def restored(self): + return self._flags & Ticket.RESTORED + @restored.setter + def restored(self, value): if value: - self._flags = Ticket.RESTORED + self._flags |= Ticket.RESTORED else: self._flags &= ~(Ticket.RESTORED) - def getRestored(self): - return self._flags & Ticket.RESTORED + @property + def banned(self): + return self._flags & Ticket.BANNED + @banned.setter + def banned(self, value): + if value: + self._flags |= Ticket.BANNED + else: + self._flags &= ~(Ticket.BANNED) def setData(self, *args, **argv): # if overwrite - set data and filter None values: diff --git a/fail2ban/tests/banmanagertestcase.py b/fail2ban/tests/banmanagertestcase.py index c9f41c6c..4a86102c 100644 --- a/fail2ban/tests/banmanagertestcase.py +++ b/fail2ban/tests/banmanagertestcase.py @@ -53,11 +53,15 @@ class AddFailure(unittest.TestCase): self.assertEqual(self.__banManager.size(), 1) def testAddDuplicateWithTime(self): + defBanTime = self.__banManager.getBanTime() + prevEndOfBanTime = 0 # add again a duplicate : - # 1) with newer start time and the same ban time + # 0) with same start time and the same (default) ban time + # 1) with newer start time and the same (default) ban time # 2) with same start time and longer ban time # 3) with permanent ban time (-1) for tnew, btnew in ( + (1167605999.0, None), (1167605999.0 + 100, None), (1167605999.0, 24*60*60), (1167605999.0, -1), @@ -71,9 +75,14 @@ class AddFailure(unittest.TestCase): self.assertEqual(self.__banManager.size(), 1) # pop ticket and check it was prolonged : banticket = self.__banManager.getTicketByID(ticket2.getID()) - self.assertEqual(banticket.getTime(), ticket2.getTime()) - self.assertEqual(banticket.getTime(), ticket2.getTime()) - self.assertEqual(banticket.getBanTime(), ticket2.getBanTime(self.__banManager.getBanTime())) + self.assertEqual(banticket.getEndOfBanTime(defBanTime), ticket2.getEndOfBanTime(defBanTime)) + self.assertTrue(banticket.getEndOfBanTime(defBanTime) > prevEndOfBanTime) + prevEndOfBanTime = ticket1.getEndOfBanTime(defBanTime) + # but the start time should not be changed (+ 100 is ignored): + self.assertEqual(banticket.getTime(), 1167605999.0) + # if prolong to permanent, it should also have permanent ban time: + if btnew == -1: + self.assertEqual(banticket.getBanTime(defBanTime), -1) def testInListOK(self): self.assertTrue(self.__banManager.addBanTicket(self.__ticket)) diff --git a/fail2ban/tests/tickettestcase.py b/fail2ban/tests/tickettestcase.py index 68a44bb5..277c2f28 100644 --- a/fail2ban/tests/tickettestcase.py +++ b/fail2ban/tests/tickettestcase.py @@ -108,6 +108,24 @@ class TicketTests(unittest.TestCase): self.assertEqual(ft2.getLastTime(), ft.getLastTime()) self.assertEqual(ft2.getBanTime(), ft.getBanTime()) + def testTicketFlags(self): + flags = ('restored', 'banned') + ticket = Ticket('test', 0) + trueflags = [] + for v in (True, False, True): + for f in flags: + setattr(ticket, f, v) + if v: + trueflags.append(f) + else: + trueflags.remove(f) + for f2 in flags: + self.assertEqual(bool(getattr(ticket, f2)), f2 in trueflags) + ## inherite props from another tockets: + ticket = FailTicket(ticket=ticket) + for f2 in flags: + self.assertTrue(bool(getattr(ticket, f2))) + def testTicketData(self): t = BanTicket('193.168.0.128', None, ['first', 'second']) # expand data (no overwrites, matches are available) : From a20f325f80489d392902751db7f30fd67aa393bb Mon Sep 17 00:00:00 2001 From: sebres Date: Fri, 9 Sep 2016 17:36:01 +0200 Subject: [PATCH 13/27] database: stability fix - repack cursor iterator as long as locked --- fail2ban/server/database.py | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/fail2ban/server/database.py b/fail2ban/server/database.py index 24445f3d..639331bf 100644 --- a/fail2ban/server/database.py +++ b/fail2ban/server/database.py @@ -482,7 +482,8 @@ class Fail2BanDb(object): queryArgs.append(str(ip)) query += " ORDER BY ip, timeofban desc" - return cur.execute(query, queryArgs) + # repack iterator as long as in lock: + return list(cur.execute(query, queryArgs)) def getBans(self, **kwargs): """Get bans from the database. @@ -581,7 +582,6 @@ class Fail2BanDb(object): self._bansMergedCache[cacheKey] = tickets if ip is None else ticket return tickets if ip is None else ticket - @commitandrollback def _getCurrentBans(self, cur, jail = None, ip = None, forbantime=None, fromtime=None): if fromtime is None: fromtime = MyTime.time() @@ -606,7 +606,9 @@ class Fail2BanDb(object): tickets = [] ticket = None - results = list(self._getCurrentBans(jail=jail, ip=ip, forbantime=forbantime, fromtime=fromtime)) + with self._lock: + results = list(self._getCurrentBans(self._db.cursor(), + jail=jail, ip=ip, forbantime=forbantime, fromtime=fromtime)) if results: for banip, timeofban, data in results: From e0347bb3a03175a740fe7654ba2df0dc562c09fa Mon Sep 17 00:00:00 2001 From: sebres Date: Fri, 9 Sep 2016 17:50:25 +0200 Subject: [PATCH 14/27] assertLogged extended with parameter wait (to wait up to specified timeout, before we throw assert exception) + test cases rewritten using that --- fail2ban/tests/fail2banclienttestcase.py | 58 +++++++++--------------- fail2ban/tests/utils.py | 37 +++++++++++---- 2 files changed, 49 insertions(+), 46 deletions(-) diff --git a/fail2ban/tests/fail2banclienttestcase.py b/fail2ban/tests/fail2banclienttestcase.py index 2804fcd4..8159a9f6 100644 --- a/fail2ban/tests/fail2banclienttestcase.py +++ b/fail2ban/tests/fail2banclienttestcase.py @@ -737,11 +737,9 @@ class Fail2banServerTest(Fail2banClientServerBase): if DefLogSys.level < logging.DEBUG: # if HEAVYDEBUG _out_file(test1log) self.execSuccess(startparams, "reload") - self.assertTrue( - Utils.wait_for(lambda: \ - self._is_logged("Reload finished.") and - self._is_logged("1 ticket(s) in 'test-jail1") - , MID_WAITTIME)) + self.assertLogged( + "Reload finished.", + "1 ticket(s) in 'test-jail1", all=True, wait=MID_WAITTIME) self.assertLogged("Added logfile: %r" % test1log) self.assertLogged("[test-jail1] Ban 192.0.2.1") # test actions started: @@ -757,8 +755,7 @@ class Fail2banServerTest(Fail2banClientServerBase): if DefLogSys.level < logging.DEBUG: # if HEAVYDEBUG _out_file(test1log) self.execSuccess(startparams, "reload") - self.assertTrue( - Utils.wait_for(lambda: self._is_logged("Reload finished."), MID_WAITTIME)) + self.assertLogged("Reload finished.", all=True, wait=MID_WAITTIME) # test not unbanned / banned again: self.assertNotLogged( "[test-jail1] Unban 192.0.2.1", @@ -784,8 +781,7 @@ class Fail2banServerTest(Fail2banClientServerBase): reload=" echo '[] %s: reloaded.'" % "test-action1", stop= " echo '[] %s: stopped.'" % "test-action1") self.execSuccess(startparams, "reload") - self.assertTrue( - Utils.wait_for(lambda: self._is_logged("Reload finished."), MID_WAITTIME)) + self.assertLogged("Reload finished.", all=True, wait=MID_WAITTIME) # test not unbanned / banned again: self.assertNotLogged( "[test-jail1] Unban 192.0.2.1", @@ -821,11 +817,9 @@ class Fail2banServerTest(Fail2banClientServerBase): if DefLogSys.level < logging.DEBUG: # if HEAVYDEBUG _out_file(test2log) # test all will be found in jail1 and one in jail2: - self.assertTrue( - Utils.wait_for(lambda: \ - self._is_logged("2 ticket(s) in 'test-jail2") and - self._is_logged("5 ticket(s) in 'test-jail1") - , MID_WAITTIME)) + self.assertLogged( + "2 ticket(s) in 'test-jail2", + "5 ticket(s) in 'test-jail1", all=True, wait=MID_WAITTIME) self.assertLogged( "[test-jail1] Ban 192.0.2.2", "[test-jail1] Ban 192.0.2.3", @@ -848,12 +842,10 @@ class Fail2banServerTest(Fail2banClientServerBase): self.pruneLog("[test-phase 2c]") self.execSuccess(startparams, "restart", "test-jail2") - self.assertTrue( - Utils.wait_for(lambda: \ - self._is_logged("Reload finished.") and - self._is_logged("Restore Ban") and - self._is_logged("2 ticket(s) in 'test-jail2") - , MID_WAITTIME)) + self.assertLogged( + "Reload finished.", + "Restore Ban", + "2 ticket(s) in 'test-jail2", all=True, wait=MID_WAITTIME) # stop/start and unban/restore ban: self.assertLogged( "Jail 'test-jail2' stopped", @@ -868,11 +860,9 @@ class Fail2banServerTest(Fail2banClientServerBase): self.pruneLog("[test-phase 2d]") self.execSuccess(startparams, "restart", "--unban", "test-jail2") - self.assertTrue( - Utils.wait_for(lambda: \ - self._is_logged("Reload finished.") and - self._is_logged("Jail 'test-jail2' started") - , MID_WAITTIME)) + self.assertLogged( + "Reload finished.", + "Jail 'test-jail2' started", all=True, wait=MID_WAITTIME) self.assertLogged( "Jail 'test-jail2' stopped", "Jail 'test-jail2' started", @@ -888,8 +878,8 @@ class Fail2banServerTest(Fail2banClientServerBase): # reload jail1 without restart (without ban/unban): self.pruneLog("[test-phase 3]") self.execSuccess(startparams, "reload", "test-jail1") - self.assertTrue( - Utils.wait_for(lambda: self._is_logged("Reload finished."), MID_WAITTIME)) + self.assertLogged( + "Reload finished.", all=True, wait=MID_WAITTIME) self.assertLogged( "Reload jail 'test-jail1'", "Jail 'test-jail1' reloaded", all=True) @@ -903,8 +893,7 @@ class Fail2banServerTest(Fail2banClientServerBase): self.pruneLog("[test-phase 4]") _write_jail_cfg(enabled=[1]) self.execSuccess(startparams, "reload") - self.assertTrue( - Utils.wait_for(lambda: self._is_logged("Reload finished."), MID_WAITTIME)) + self.assertLogged("Reload finished.", all=True, wait=MID_WAITTIME) # test both jails should be reloaded: self.assertLogged( "Reload jail 'test-jail1'") @@ -926,11 +915,9 @@ class Fail2banServerTest(Fail2banClientServerBase): )) if DefLogSys.level < logging.DEBUG: # if HEAVYDEBUG _out_file(test1log) - self.assertTrue( - Utils.wait_for(lambda: \ - self._is_logged("6 ticket(s) in 'test-jail1") and - self._is_logged("[test-jail1] 192.0.2.1 already banned") - , MID_WAITTIME)) + self.assertLogged( + "6 ticket(s) in 'test-jail1", + "[test-jail1] 192.0.2.1 already banned", all=True, wait=MID_WAITTIME) # test "failure" regexp still available: self.assertLogged( "[test-jail1] Found 192.0.2.1", @@ -953,8 +940,7 @@ class Fail2banServerTest(Fail2banClientServerBase): self.pruneLog("[test-phase 7]") self.execSuccess(startparams, "reload", "--unban") - self.assertTrue( - Utils.wait_for(lambda: self._is_logged("Reload finished."), MID_WAITTIME)) + self.assertLogged("Reload finished.", all=True, wait=MID_WAITTIME) # reloads unbanned all: self.assertLogged( "Jail 'test-jail1' reloaded", diff --git a/fail2ban/tests/utils.py b/fail2ban/tests/utils.py index 6eaf560b..76bb724c 100644 --- a/fail2ban/tests/utils.py +++ b/fail2ban/tests/utils.py @@ -589,8 +589,21 @@ class LogCaptureTestCase(unittest.TestCase): logSys.handlers = self._old_handlers logSys.level = self._old_level - def _is_logged(self, s): - return s in self._log.getvalue() + def _is_logged(self, *s, **kwargs): + logged = self._log.getvalue() + if not kwargs.get('all', False): + # at least one entry should be found: + for s_ in s: + if s_ in logged: + return True + if True: # pragma: no cover + return False + else: + # each entry should be found: + for s_ in s: + if s_ not in logged: # pragma: no cover + return False + return True def assertLogged(self, *s, **kwargs): """Assert that one of the strings was logged @@ -604,19 +617,23 @@ class LogCaptureTestCase(unittest.TestCase): Test should succeed if string (or any of the listed) is present in the log all : boolean (default False) if True should fail if any of s not logged """ - logged = self._log.getvalue() + wait = kwargs.get('wait', None) + if wait: + res = Utils.wait_for(lambda: self._is_logged(*s, **kwargs), wait) + else: + res = self._is_logged(*s, **kwargs) if not kwargs.get('all', False): # at least one entry should be found: - for s_ in s: - if s_ in logged: - return - if True: # pragma: no cover + if not res: # pragma: no cover + logged = self._log.getvalue() self.fail("None among %r was found in the log: ===\n%s===" % (s, logged)) else: # each entry should be found: - for s_ in s: - if s_ not in logged: # pragma: no cover - self.fail("%r was not found in the log: ===\n%s===" % (s_, logged)) + if not res: # pragma: no cover + logged = self._log.getvalue() + for s_ in s: + if s_ not in logged: + self.fail("%r was not found in the log: ===\n%s===" % (s_, logged)) def assertNotLogged(self, *s, **kwargs): """Assert that strings were not logged From ebd864660a4377a4af3fa77793517db4b97f3833 Mon Sep 17 00:00:00 2001 From: sebres Date: Fri, 9 Sep 2016 18:28:47 +0200 Subject: [PATCH 15/27] normalize usage of preferred encoding (and decode any to string); python 3.x compatibility (used uni_decode for string representation of stdout/stderr, unified test cases) amend for #1542 --- fail2ban/client/fail2banregex.py | 5 ++--- fail2ban/helpers.py | 34 ++++++++++++++++++++++++++++++++ fail2ban/server/database.py | 13 ++++++------ fail2ban/server/filter.py | 30 +++------------------------- fail2ban/server/filtersystemd.py | 16 ++++++--------- fail2ban/server/utils.py | 14 +++++++++---- fail2ban/tests/actiontestcase.py | 4 ++-- fail2ban/tests/filtertestcase.py | 7 +++---- fail2ban/tests/misctestcase.py | 10 ++++------ fail2ban/tests/servertestcase.py | 5 ++--- 10 files changed, 72 insertions(+), 66 deletions(-) diff --git a/fail2ban/client/fail2banregex.py b/fail2ban/client/fail2banregex.py index f36ca7b0..ea2f3a7f 100644 --- a/fail2ban/client/fail2banregex.py +++ b/fail2ban/client/fail2banregex.py @@ -29,7 +29,6 @@ __copyright__ = "Copyright (c) 2004-2008 Cyril Jaquier, 2012-2014 Yaroslav Halch __license__ = "GPL" import getopt -import locale import logging import os import shlex @@ -52,7 +51,7 @@ from .filterreader import FilterReader from ..server.filter import Filter, FileContainer from ..server.failregex import RegexException -from ..helpers import FormatterWithTraceBack, getLogger +from ..helpers import FormatterWithTraceBack, getLogger, PREFER_ENC # Gets the instance of the logger. logSys = getLogger("fail2ban") @@ -239,7 +238,7 @@ class Fail2banRegex(object): if opts.encoding: self.encoding = opts.encoding else: - self.encoding = locale.getpreferredencoding() + self.encoding = PREFER_ENC self.raw = True if opts.raw else False def decode_line(self, line): diff --git a/fail2ban/helpers.py b/fail2ban/helpers.py index 7660e64a..2738f5e6 100644 --- a/fail2ban/helpers.py +++ b/fail2ban/helpers.py @@ -21,6 +21,7 @@ __author__ = "Cyril Jaquier, Arturo 'Buanzo' Busleiman, Yaroslav Halchenko" __license__ = "GPL" import gc +import locale import logging import os import re @@ -32,6 +33,9 @@ from threading import Lock from .server.mytime import MyTime +PREFER_ENC = locale.getpreferredencoding() + + def formatExceptionInfo(): """ Consistently format exception information """ cla, exc = sys.exc_info()[:2] @@ -144,6 +148,36 @@ def splitwords(s): return filter(bool, map(str.strip, re.split('[ ,\n]+', s))) +# +# Following "uni_decode" function unified python independent any to string converting +# +# Typical example resp. work-case for understanding the coding/decoding issues: +# +# [isinstance('', str), isinstance(b'', str), isinstance(u'', str)] +# [True, True, False]; # -- python2 +# [True, False, True]; # -- python3 +# +if sys.version_info >= (3,): + def uni_decode(x, enc=PREFER_ENC, errors='strict'): + try: + if isinstance(x, bytes): + return x.decode(enc, errors) + return x + except (UnicodeDecodeError, UnicodeEncodeError): # pragma: no cover - unsure if reachable + if errors != 'strict': + raise + return uni_decode(x, enc, 'replace') +else: + def uni_decode(x, enc=PREFER_ENC, errors='strict'): + try: + if isinstance(x, unicode): + return x.encode(enc, errors) + return x + except (UnicodeDecodeError, UnicodeEncodeError): # pragma: no cover - unsure if reachable + if errors != 'strict': + raise + return uni_decode(x, enc, 'replace') + class BgService(object): """Background servicing diff --git a/fail2ban/server/database.py b/fail2ban/server/database.py index 639331bf..120619f9 100644 --- a/fail2ban/server/database.py +++ b/fail2ban/server/database.py @@ -22,7 +22,6 @@ __copyright__ = "Copyright (c) 2013 Steven Hiscocks" __license__ = "GPL" import json -import locale import shutil import sqlite3 import sys @@ -32,7 +31,7 @@ from threading import RLock from .mytime import MyTime from .ticket import FailTicket -from ..helpers import getLogger +from ..helpers import getLogger, PREFER_ENC # Gets the instance of the logger. logSys = getLogger(__name__) @@ -41,7 +40,7 @@ if sys.version_info >= (3,): def _json_dumps_safe(x): try: x = json.dumps(x, ensure_ascii=False).encode( - locale.getpreferredencoding(), 'replace') + PREFER_ENC, 'replace') except Exception as e: # pragma: no cover logSys.error('json dumps failed: %s', e) x = '{}' @@ -50,7 +49,7 @@ if sys.version_info >= (3,): def _json_loads_safe(x): try: x = json.loads(x.decode( - locale.getpreferredencoding(), 'replace')) + PREFER_ENC, 'replace')) except Exception as e: # pragma: no cover logSys.error('json loads failed: %s', e) x = {} @@ -62,14 +61,14 @@ else: elif isinstance(x, list): return [_normalize(element) for element in x] elif isinstance(x, unicode): - return x.encode(locale.getpreferredencoding()) + return x.encode(PREFER_ENC) else: return x def _json_dumps_safe(x): try: x = json.dumps(_normalize(x), ensure_ascii=False).decode( - locale.getpreferredencoding(), 'replace') + PREFER_ENC, 'replace') except Exception as e: # pragma: no cover logSys.error('json dumps failed: %s', e) x = '{}' @@ -78,7 +77,7 @@ else: def _json_loads_safe(x): try: x = _normalize(json.loads(x.decode( - locale.getpreferredencoding(), 'replace'))) + PREFER_ENC, 'replace'))) except Exception as e: # pragma: no cover logSys.error('json loads failed: %s', e) x = {} diff --git a/fail2ban/server/filter.py b/fail2ban/server/filter.py index ab6e7b15..08f3e77d 100644 --- a/fail2ban/server/filter.py +++ b/fail2ban/server/filter.py @@ -24,7 +24,6 @@ __license__ = "GPL" import codecs import datetime import fcntl -import locale import logging import os import re @@ -40,7 +39,7 @@ from .datetemplate import DatePatternRegex, DateEpoch, DateTai64n from .mytime import MyTime from .failregex import FailRegex, Regex, RegexException from .action import CommandAction -from ..helpers import getLogger +from ..helpers import getLogger, PREFER_ENC # Gets the instance of the logger. logSys = getLogger(__name__) @@ -87,7 +86,7 @@ class Filter(JailThread): ## External command self.__ignoreCommand = False ## Default or preferred encoding (to decode bytes from file or journal): - self.__encoding = locale.getpreferredencoding() + self.__encoding = PREFER_ENC ## Error counter (protected, so can be used in filter implementations) ## if it reached 100 (at once), run-cycle will go idle self._errors = 0 @@ -329,7 +328,7 @@ class Filter(JailThread): def setLogEncoding(self, encoding): if encoding.lower() == "auto": - encoding = locale.getpreferredencoding() + encoding = PREFER_ENC codecs.lookup(encoding) # Raise LookupError if invalid codec self.__encoding = encoding logSys.info(" encoding: %s" % encoding) @@ -452,29 +451,6 @@ class Filter(JailThread): return False - if sys.version_info >= (3,): - @staticmethod - def uni_decode(x, enc, errors='strict'): - try: - if isinstance(x, bytes): - return x.decode(enc, errors) - return x - except (UnicodeDecodeError, UnicodeEncodeError): # pragma: no cover - unsure if reachable - if errors != 'strict': - raise - return uni_decode(x, enc, 'replace') - else: - @staticmethod - def uni_decode(x, enc, errors='strict'): - try: - if isinstance(x, unicode): - return x.encode(enc, errors) - return x - except (UnicodeDecodeError, UnicodeEncodeError): # pragma: no cover - unsure if reachable - if errors != 'strict': - raise - return uni_decode(x, enc, 'replace') - def processLine(self, line, date=None, returnRawHost=False, checkAllRegex=False, checkFindTime=False): """Split the time portion from log msg and return findFailures on them diff --git a/fail2ban/server/filtersystemd.py b/fail2ban/server/filtersystemd.py index 0b6c4074..f9f9395c 100644 --- a/fail2ban/server/filtersystemd.py +++ b/fail2ban/server/filtersystemd.py @@ -34,7 +34,7 @@ from .failmanager import FailManagerEmpty from .filter import JournalFilter, Filter from .mytime import MyTime from .utils import Utils -from ..helpers import getLogger, logging, splitwords +from ..helpers import getLogger, logging, splitwords, uni_decode # Gets the instance of the logger. logSys = getLogger(__name__) @@ -174,10 +174,6 @@ class FilterSystemd(JournalFilter): # pragma: systemd no cover def getJournalMatch(self): return self.__matches - def uni_decode(self, x): - v = Filter.uni_decode(x, self.getLogEncoding()) - return v - ## # Format journal log entry into syslog style # @@ -186,16 +182,16 @@ class FilterSystemd(JournalFilter): # pragma: systemd no cover def formatJournalEntry(self, logentry): # Be sure, all argument of line tuple should have the same type: - uni_decode = self.uni_decode + enc = self.getLogEncoding() logelements = [] v = logentry.get('_HOSTNAME') if v: - logelements.append(uni_decode(v)) + logelements.append(uni_decode(v, enc)) v = logentry.get('SYSLOG_IDENTIFIER') if not v: v = logentry.get('_COMM') if v: - logelements.append(uni_decode(v)) + logelements.append(uni_decode(v, enc)) v = logentry.get('SYSLOG_PID') if not v: v = logentry.get('_PID') @@ -210,9 +206,9 @@ class FilterSystemd(JournalFilter): # pragma: systemd no cover logelements.append("[%12.6f]" % monotonic.total_seconds()) msg = logentry.get('MESSAGE','') if isinstance(msg, list): - logelements.append(" ".join(uni_decode(v) for v in msg)) + logelements.append(" ".join(uni_decode(v, enc) for v in msg)) else: - logelements.append(uni_decode(msg)) + logelements.append(uni_decode(msg, enc)) logline = " ".join(logelements) diff --git a/fail2ban/server/utils.py b/fail2ban/server/utils.py index 738394c3..a8a00257 100644 --- a/fail2ban/server/utils.py +++ b/fail2ban/server/utils.py @@ -21,8 +21,14 @@ __author__ = "Serg G. Brester (sebres) and Fail2Ban Contributors" __copyright__ = "Copyright (c) 2004 Cyril Jaquier, 2011-2012 Yaroslav Halchenko, 2012-2015 Serg G. Brester" __license__ = "GPL" -import logging, os, fcntl, subprocess, time, signal -from ..helpers import getLogger +import fcntl +import logging +import os +import signal +import subprocess +import sys +import time +from ..helpers import getLogger, uni_decode # Gets the instance of the logger. logSys = getLogger(__name__) @@ -179,7 +185,7 @@ class Utils(): if stdout is not None and stdout != '' and std_level >= logSys.getEffectiveLevel(): logSys.log(std_level, "%s -- stdout:", realCmd) for l in stdout.splitlines(): - logSys.log(std_level, " -- stdout: %r", l) + logSys.log(std_level, " -- stdout: %r", uni_decode(l)) popen.stdout.close() if popen.stderr: try: @@ -191,7 +197,7 @@ class Utils(): if stderr is not None and stderr != '' and std_level >= logSys.getEffectiveLevel(): logSys.log(std_level, "%s -- stderr:", realCmd) for l in stderr.splitlines(): - logSys.log(std_level, " -- stderr: %r", l) + logSys.log(std_level, " -- stderr: %r", uni_decode(l)) popen.stderr.close() success = False diff --git a/fail2ban/tests/actiontestcase.py b/fail2ban/tests/actiontestcase.py index 166450bb..cacb5e17 100644 --- a/fail2ban/tests/actiontestcase.py +++ b/fail2ban/tests/actiontestcase.py @@ -399,11 +399,11 @@ class CommandActionTest(LogCaptureTestCase): def testCaptureStdOutErr(self): CommandAction.executeCmd('echo "How now brown cow"') - self.assertLogged("stdout: 'How now brown cow'\n", "stdout: b'How now brown cow'\n") + self.assertLogged("stdout: 'How now brown cow'\n") CommandAction.executeCmd( 'echo "The rain in Spain stays mainly in the plain" 1>&2') self.assertLogged( - "stderr: 'The rain in Spain stays mainly in the plain'\n", "stderr: b'The rain in Spain stays mainly in the plain'\n") + "stderr: 'The rain in Spain stays mainly in the plain'\n") def testCallingMap(self): mymap = CallingMap(callme=lambda: str(10), error=lambda: int('a'), diff --git a/fail2ban/tests/filtertestcase.py b/fail2ban/tests/filtertestcase.py index f7394a8e..15495655 100644 --- a/fail2ban/tests/filtertestcase.py +++ b/fail2ban/tests/filtertestcase.py @@ -38,11 +38,11 @@ except ImportError: from ..server.jail import Jail from ..server.filterpoll import FilterPoll -from ..server.filter import Filter, FileFilter, FileContainer, locale +from ..server.filter import Filter, FileFilter, FileContainer from ..server.failmanager import FailManagerEmpty from ..server.ipdns import DNSUtils, IPAddr from ..server.mytime import MyTime -from ..server.utils import Utils +from ..server.utils import Utils, uni_decode from .utils import setUpMyTime, tearDownMyTime, mtimesleep, LogCaptureTestCase from .dummyjail import DummyJail @@ -311,8 +311,7 @@ class BasicFilter(unittest.TestCase): b'Fail for "g\xc3\xb6ran" from 192.0.2.1' ): # join should work if all arguments have the same type: - enc = locale.getpreferredencoding() - "".join([Filter.uni_decode(v, enc) for v in (a1, a2, a3)]) + "".join([uni_decode(v) for v in (a1, a2, a3)]) class IgnoreIP(LogCaptureTestCase): diff --git a/fail2ban/tests/misctestcase.py b/fail2ban/tests/misctestcase.py index 5b6b93a6..8fb393ea 100644 --- a/fail2ban/tests/misctestcase.py +++ b/fail2ban/tests/misctestcase.py @@ -35,7 +35,7 @@ from StringIO import StringIO from utils import LogCaptureTestCase, logSys as DefLogSys -from ..helpers import formatExceptionInfo, mbasename, TraceBack, FormatterWithTraceBack, getLogger +from ..helpers import formatExceptionInfo, mbasename, TraceBack, FormatterWithTraceBack, getLogger, uni_decode from ..helpers import splitwords from ..server.datedetector import DateDetector from ..server.datetemplate import DatePatternRegex @@ -74,16 +74,14 @@ class HelpersTest(unittest.TestCase): if sys.version_info >= (2,7): def _sh_call(cmd): - import subprocess, locale + import subprocess ret = subprocess.check_output(cmd, shell=True) - if sys.version_info >= (3,): - ret = ret.decode(locale.getpreferredencoding(), 'replace') - return str(ret).rstrip() + return uni_decode(ret).rstrip() else: def _sh_call(cmd): import subprocess ret = subprocess.Popen(cmd, shell=True, stdout=subprocess.PIPE).stdout.read() - return str(ret).rstrip() + return uni_decode(ret).rstrip() def _getSysPythonVersion(): return _sh_call("fail2ban-python -c 'import sys; print(tuple(sys.version_info))'") diff --git a/fail2ban/tests/servertestcase.py b/fail2ban/tests/servertestcase.py index 3ca8049b..d044da4b 100644 --- a/fail2ban/tests/servertestcase.py +++ b/fail2ban/tests/servertestcase.py @@ -28,7 +28,6 @@ import unittest import time import tempfile import os -import locale import sys import platform @@ -40,7 +39,7 @@ from ..server.jail import Jail from ..server.jailthread import JailThread from ..server.utils import Utils from .utils import LogCaptureTestCase -from ..helpers import getLogger +from ..helpers import getLogger, PREFER_ENC from .. import version try: @@ -354,7 +353,7 @@ class Transmitter(TransmitterBase): def testJailLogEncoding(self): self.setGetTest("logencoding", "UTF-8", jail=self.jailName) self.setGetTest("logencoding", "ascii", jail=self.jailName) - self.setGetTest("logencoding", "auto", locale.getpreferredencoding(), + self.setGetTest("logencoding", "auto", PREFER_ENC, jail=self.jailName) self.setGetTestNOK("logencoding", "Monkey", jail=self.jailName) From 20b92f3ead34fe34f4d97077e73d6edaa80e0244 Mon Sep 17 00:00:00 2001 From: sebres Date: Fri, 9 Sep 2016 20:31:52 +0200 Subject: [PATCH 16/27] fail2ban-regex: build replacement of `` substitution corresponding parameter `usedns` - now also in fail2ban-regex (amend) --- fail2ban/client/fail2banregex.py | 5 +++++ fail2ban/tests/fail2banregextestcase.py | 9 +++++++++ 2 files changed, 14 insertions(+) diff --git a/fail2ban/client/fail2banregex.py b/fail2ban/client/fail2banregex.py index ea2f3a7f..f99f9f01 100644 --- a/fail2ban/client/fail2banregex.py +++ b/fail2ban/client/fail2banregex.py @@ -126,6 +126,9 @@ Report bugs to https://github.com/fail2ban/fail2ban/issues help="File encoding. Default: system locale"), Option("-r", "--raw", action='store_true', help="Raw hosts, don't resolve dns"), + Option("--usedns", action='store', default=None, + help="DNS specified replacement of tags in regexp " + "('yes' - matches all form of hosts, 'no' - IP addresses only)"), Option("-L", "--maxlines", type=int, default=0, help="maxlines for multi-line regex"), Option("-m", "--journalmatch", @@ -240,6 +243,8 @@ class Fail2banRegex(object): else: self.encoding = PREFER_ENC self.raw = True if opts.raw else False + if opts.usedns: + self._filter.setUseDns(opts.usedns) def decode_line(self, line): return FileContainer.decode_line('', self.encoding, line) diff --git a/fail2ban/tests/fail2banregextestcase.py b/fail2ban/tests/fail2banregextestcase.py index 1d38a58e..0154e5af 100644 --- a/fail2ban/tests/fail2banregextestcase.py +++ b/fail2ban/tests/fail2banregextestcase.py @@ -131,6 +131,15 @@ class Fail2banRegexTest(LogCaptureTestCase): self.assertTrue(fail2banRegex.start(opts, args)) self.assertLogged('Lines: 19 lines, 0 ignored, 16 matched, 3 missed') + def testDirectRE_1raw_noDns(self): + (opts, args, fail2banRegex) = _Fail2banRegex( + "--print-all-matched", "--raw", "--usedns=no", + Fail2banRegexTest.FILENAME_01, + Fail2banRegexTest.RE_00 + ) + self.assertTrue(fail2banRegex.start(opts, args)) + self.assertLogged('Lines: 19 lines, 0 ignored, 13 matched, 6 missed') + def testDirectRE_2(self): (opts, args, fail2banRegex) = _Fail2banRegex( "--print-all-matched", From 35ce1166b61a69c0216c6880b166d0d3bad2b8a7 Mon Sep 17 00:00:00 2001 From: sebres Date: Wed, 21 Sep 2016 09:17:56 +0200 Subject: [PATCH 17/27] allows to update some configuration options (read with config-readers) with command line option, e. g.: ```bash ## start server with DEBUG log-level (ignore level read from fail2ban.conf): fail2ban-client --loglevel DEBUG start ## or fail2ban-server -c /cfg/path --loglevel DEBUG start ## keep server log-level by reload (without restart it) fail2ban-client --loglevel DEBUG reload ## switch log-level back to INFO: fail2ban-client set loglevel INFO ``` --- fail2ban/client/configurator.py | 4 ++-- fail2ban/client/fail2bancmdline.py | 2 +- fail2ban/client/fail2banreader.py | 4 +++- 3 files changed, 6 insertions(+), 4 deletions(-) diff --git a/fail2ban/client/configurator.py b/fail2ban/client/configurator.py index 3b9845b6..4d28238f 100644 --- a/fail2ban/client/configurator.py +++ b/fail2ban/client/configurator.py @@ -72,8 +72,8 @@ class Configurator: def getEarlyOptions(self): return self.__fail2ban.getEarlyOptions() - def getOptions(self, jail = None): - self.__fail2ban.getOptions() + def getOptions(self, jail=None, updateMainOpt=None): + self.__fail2ban.getOptions(updateMainOpt) return self.__jails.getOptions(jail) def convertToProtocol(self): diff --git a/fail2ban/client/fail2bancmdline.py b/fail2ban/client/fail2bancmdline.py index 356255af..e1bc5f1e 100644 --- a/fail2ban/client/fail2bancmdline.py +++ b/fail2ban/client/fail2bancmdline.py @@ -242,7 +242,7 @@ class Fail2banCmdLine(): try: self.configurator.Reload() self.configurator.readAll() - ret = self.configurator.getOptions(jail) + ret = self.configurator.getOptions(jail, self._conf) self.configurator.convertToProtocol() stream = self.configurator.getConfigStream() except Exception as e: diff --git a/fail2ban/client/fail2banreader.py b/fail2ban/client/fail2banreader.py index b3012c9b..8e1b0e5c 100644 --- a/fail2ban/client/fail2banreader.py +++ b/fail2ban/client/fail2banreader.py @@ -49,13 +49,15 @@ class Fail2banReader(ConfigReader): ] return ConfigReader.getOptions(self, "Definition", opts) - def getOptions(self): + def getOptions(self, updateMainOpt=None): opts = [["string", "loglevel", "INFO" ], ["string", "logtarget", "STDERR"], ["string", "syslogsocket", "auto"], ["string", "dbfile", "/var/lib/fail2ban/fail2ban.sqlite3"], ["string", "dbpurgeage", "1d"]] self.__opts = ConfigReader.getOptions(self, "Definition", opts) + if updateMainOpt: + self.__opts.update(updateMainOpt) def convert(self): # Ensure logtarget/level set first so any db errors are captured From d153555a07ec81dabe4678ea06c8e644afc8ec40 Mon Sep 17 00:00:00 2001 From: sebres Date: Thu, 22 Sep 2016 14:28:47 +0200 Subject: [PATCH 18/27] increase default wait operation (sleep time, threshold interval) - avowedly greater inertance, but fewer system load by many jails resp. log files; waiting with `wait_for` extended with verifying of active flag; implemented better error handling in some multi-threaded routines; shutdown of jails rewritten (faster and safer, does not breaks shutdown process if some error occurred); --- fail2ban/server/actions.py | 5 +- fail2ban/server/asyncserver.py | 39 ++++++++------ fail2ban/server/filter.py | 20 ++++--- fail2ban/server/filtergamin.py | 5 +- fail2ban/server/filterpoll.py | 7 +-- fail2ban/server/filterpyinotify.py | 2 +- fail2ban/server/filtersystemd.py | 83 +++++++++++++++++++----------- fail2ban/server/jail.py | 24 ++++++--- fail2ban/server/server.py | 20 ++++--- fail2ban/server/utils.py | 4 +- 10 files changed, 130 insertions(+), 79 deletions(-) diff --git a/fail2ban/server/actions.py b/fail2ban/server/actions.py index bc8684b5..eed481d7 100644 --- a/fail2ban/server/actions.py +++ b/fail2ban/server/actions.py @@ -281,9 +281,10 @@ class Actions(JailThread, Mapping): exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) while self.active: if self.idle: - time.sleep(self.sleeptime) + Utils.wait_for(lambda: not self.active or not self.idle, + self.sleeptime * 10, self.sleeptime) continue - if not Utils.wait_for(self.__checkBan, self.sleeptime): + if not Utils.wait_for(lambda: not self.active or self.__checkBan(), self.sleeptime): self.__checkUnBan() self.__flushBan() diff --git a/fail2ban/server/asyncserver.py b/fail2ban/server/asyncserver.py index ffb20503..a489b585 100644 --- a/fail2ban/server/asyncserver.py +++ b/fail2ban/server/asyncserver.py @@ -67,23 +67,28 @@ class RequestHandler(asynchat.async_chat): # This method is called once we have a complete request. def found_terminator(self): - # Pop whole buffer - message = self.__buffer - self.__buffer = [] - # Joins the buffer items. - message = CSPROTO.EMPTY.join(message) - # Closes the channel if close was received - if message == CSPROTO.CLOSE: - self.close_when_done() - return - # Deserialize - message = loads(message) - # Gives the message to the transmitter. - message = self.__transmitter.proceed(message) - # Serializes the response. - message = dumps(message, HIGHEST_PROTOCOL) - # Sends the response to the client. - self.push(message + CSPROTO.END) + try: + # Pop whole buffer + message = self.__buffer + self.__buffer = [] + # Joins the buffer items. + message = CSPROTO.EMPTY.join(message) + # Closes the channel if close was received + if message == CSPROTO.CLOSE: + self.close_when_done() + return + # Deserialize + message = loads(message) + # Gives the message to the transmitter. + message = self.__transmitter.proceed(message) + # Serializes the response. + message = dumps(message, HIGHEST_PROTOCOL) + # Sends the response to the client. + self.push(message + CSPROTO.END) + except Exception as e: # pragma: no cover + logSys.error("Caught unhandled exception: %r", e, + exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) + def handle_error(self): e1, e2 = formatExceptionInfo() diff --git a/fail2ban/server/filter.py b/fail2ban/server/filter.py index 08f3e77d..ac64fb86 100644 --- a/fail2ban/server/filter.py +++ b/fail2ban/server/filter.py @@ -501,14 +501,18 @@ class Filter(JailThread): except Exception as e: logSys.error("Failed to process line: %r, caught exception: %r", line, e, exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) - # incr error counter, stop processing (going idle) after 100th error : - self._errors += 1 - # sleep a little bit (to get around time-related errors): - time.sleep(self.sleeptime) - if self._errors >= 100: - logSys.error("Too many errors at once (%s), going idle", self._errors) - self._errors //= 2 - self.idle = True + # incr common error counter: + self.commonError() + + def commonError(self): + # incr error counter, stop processing (going idle) after 100th error : + self._errors += 1 + # sleep a little bit (to get around time-related errors): + time.sleep(self.sleeptime) + if self._errors >= 100: + logSys.error("Too many errors at once (%s), going idle", self._errors) + self._errors //= 2 + self.idle = True ## # Returns true if the line should be ignored. diff --git a/fail2ban/server/filtergamin.py b/fail2ban/server/filtergamin.py index 39793067..a8d03ebd 100644 --- a/fail2ban/server/filtergamin.py +++ b/fail2ban/server/filtergamin.py @@ -124,12 +124,13 @@ class FilterGamin(FileFilter): while self.active: if self.idle: # wait a little bit here for not idle, to prevent hi-load: - if not Utils.wait_for(lambda: not self.idle, + if not Utils.wait_for(lambda: not self.active or not self.idle, self.sleeptime * 10, self.sleeptime ): self.ticks += 1 continue - Utils.wait_for(self._handleEvents, self.sleeptime) + Utils.wait_for(lambda: not self.active or self._handleEvents(), + self.sleeptime) self.ticks += 1 logSys.debug(self.jail.name + ": filter terminated") return True diff --git a/fail2ban/server/filterpoll.py b/fail2ban/server/filterpoll.py index f66be42b..d0660f15 100644 --- a/fail2ban/server/filterpoll.py +++ b/fail2ban/server/filterpoll.py @@ -101,14 +101,15 @@ class FilterPoll(FileFilter): logSys.log(6, "Woke up idle=%s with %d files monitored", self.idle, self.getLogCount()) if self.idle: - if not Utils.wait_for(lambda: not self.idle, + if not Utils.wait_for(lambda: not self.active or not self.idle, self.sleeptime * 10, self.sleeptime ): self.ticks += 1 continue # Get file modification modlst = [] - Utils.wait_for(lambda: self.getModified(modlst), self.sleeptime) + Utils.wait_for(lambda: not self.active or self.getModified(modlst), + self.sleeptime) for filename in modlst: self.getFailures(filename) self.__modified = True @@ -162,7 +163,7 @@ class FilterPoll(FileFilter): exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) # increase file and common error counters: self.__file404Cnt[filename] += 1 - self._errors += 1 + self.commonError() if self.__file404Cnt[filename] > 50: logSys.warning("Too many errors. Remove file %r from monitoring process", filename) self.__file404Cnt[filename] = 0 diff --git a/fail2ban/server/filterpyinotify.py b/fail2ban/server/filterpyinotify.py index 1e08f250..9b444844 100644 --- a/fail2ban/server/filterpyinotify.py +++ b/fail2ban/server/filterpyinotify.py @@ -178,7 +178,7 @@ class FilterPyinotify(FileFilter): # slow check events while idle: def __check_events(self, *args, **kwargs): if self.idle: - if Utils.wait_for(lambda: not self.idle, + if Utils.wait_for(lambda: not self.active or not self.idle, self.sleeptime * 10, self.sleeptime ): pass diff --git a/fail2ban/server/filtersystemd.py b/fail2ban/server/filtersystemd.py index f9f9395c..a29085ba 100644 --- a/fail2ban/server/filtersystemd.py +++ b/fail2ban/server/filtersystemd.py @@ -252,40 +252,63 @@ class FilterSystemd(JournalFilter): # pragma: systemd no cover while self.active: # wait for records (or for timeout in sleeptime seconds): - self.__journal.wait(self.sleeptime) - if self.idle: - # because journal.wait will returns immediatelly if we have records in journal, - # just wait a little bit here for not idle, to prevent hi-load: - if not Utils.wait_for(lambda: not self.idle, - self.sleeptime * 10, self.sleeptime - ): + try: + ## todo: find better method as wait_for to break (e.g. notify) journal.wait(self.sleeptime), + ## don't use `journal.close()` for it, because in some python/systemd implementation it may + ## cause abnormal program termination + #self.__journal.wait(self.sleeptime) != journal.NOP + ## + ## wait for entries without sleep in intervals, because "sleeping" in journal.wait: + Utils.wait_for(lambda: not self.active or \ + self.__journal.wait(Utils.DEFAULT_SLEEP_INTERVAL) != journal.NOP, + self.sleeptime, 0.00001) + if self.idle: + # because journal.wait will returns immediatelly if we have records in journal, + # just wait a little bit here for not idle, to prevent hi-load: + if not Utils.wait_for(lambda: not self.active or not self.idle, + self.sleeptime * 10, self.sleeptime + ): + self.ticks += 1 + continue + self.__modified = 0 + while self.active: + logentry = None + try: + logentry = self.__journal.get_next() + except OSError as e: + logSys.error("Error reading line from systemd journal: %s", + e, exc_info=logSys.getEffectiveLevel() <= logging.DEBUG) self.ticks += 1 - continue - self.__modified = 0 - while self.active: - logentry = None - try: - logentry = self.__journal.get_next() - except OSError as e: - logSys.error("Error reading line from systemd journal: %s", - e, exc_info=logSys.getEffectiveLevel() <= logging.DEBUG) - self.ticks += 1 - if logentry: - self.processLineAndAdd( - *self.formatJournalEntry(logentry)) - self.__modified += 1 - if self.__modified >= 100: # todo: should be configurable + if logentry: + self.processLineAndAdd( + *self.formatJournalEntry(logentry)) + self.__modified += 1 + if self.__modified >= 100: # todo: should be configurable + break + else: break - else: + if self.__modified: + try: + while True: + ticket = self.failManager.toBan() + self.jail.putFailTicket(ticket) + except FailManagerEmpty: + self.failManager.cleanup(MyTime.time()) + except Exception as e: # pragma: no cover + if not self.active: # if not active - error by stop... break - if self.__modified: - try: - while True: - ticket = self.failManager.toBan() - self.jail.putFailTicket(ticket) - except FailManagerEmpty: - self.failManager.cleanup(MyTime.time()) + logSys.error("Caught unhandled exception in main cycle: %r", e, + exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) + # incr common error counter: + self.commonError() + # close journal: + try: + if self.__journal: + self.__journal.close() + except Exception as e: # pragma: no cover + logSys.error("Close journal failed: %r", e, + exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) logSys.debug((self.jail is not None and self.jail.name or "jailless") +" filter terminated") return True diff --git a/fail2ban/server/jail.py b/fail2ban/server/jail.py index e70eaddd..aa4a38cc 100644 --- a/fail2ban/server/jail.py +++ b/fail2ban/server/jail.py @@ -239,19 +239,31 @@ class Jail(object): Once stated, also queries the persistent database to reinstate any valid bans. """ + logSys.debug("Starting jail %r", self.name) self.filter.start() self.actions.start() self.restoreCurrentBans() logSys.info("Jail %r started", self.name) - def stop(self): + def stop(self, stop=True, join=True): """Stop the jail, by stopping filter and actions threads. """ - self.filter.stop() - self.actions.stop() - self.filter.join() - self.actions.join() - logSys.info("Jail '%s' stopped" % self.name) + if stop: + logSys.debug("Stopping jail %r", self.name) + for obj in (self.filter, self.actions): + try: + ## signal to stop filter / actions: + if stop: + obj.stop() + ## wait for end of threads: + if join: + if obj.isAlive(): + obj.join() + except Exception as e: + logSys.error("Stop %r of jail %r failed: %s", obj, self.name, e, + exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) + if join: + logSys.info("Jail %r stopped", self.name) def isAlive(self): """Check jail "isAlive" by checking filter and actions threads. diff --git a/fail2ban/server/server.py b/fail2ban/server/server.py index 97345331..a21b1fce 100644 --- a/fail2ban/server/server.py +++ b/fail2ban/server/server.py @@ -210,14 +210,14 @@ class Server: if self.__db is not None: self.__db.addJail(self.__jails[name]) - def delJail(self, name, stop=True): + def delJail(self, name, stop=True, join=True): jail = self.__jails[name] - if stop and jail.isAlive(): - logSys.debug("Stopping jail %r" % name) - jail.stop() - if self.__db is not None: - self.__db.delJail(jail) - del self.__jails[name] + if join or jail.isAlive(): + jail.stop(stop=stop, join=join) + if join: + if self.__db is not None: + self.__db.delJail(jail) + del self.__jails[name] def startJail(self, name): with self.__lock: @@ -237,8 +237,12 @@ class Server: def stopAllJail(self): logSys.info("Stopping all jails") with self.__lock: + # 1st stop all jails (signal and stop actions/filter thread): for name in self.__jails.keys(): - self.delJail(name, stop=True) + self.delJail(name, stop=True, join=False) + # 2nd wait for end and delete jails: + for name in self.__jails.keys(): + self.delJail(name, stop=False, join=True) def reloadJails(self, name, opts, begin): if begin: diff --git a/fail2ban/server/utils.py b/fail2ban/server/utils.py index a8a00257..74406363 100644 --- a/fail2ban/server/utils.py +++ b/fail2ban/server/utils.py @@ -52,8 +52,8 @@ class Utils(): """Utilities provide diverse static methods like executes OS shell commands, etc. """ - DEFAULT_SLEEP_TIME = 0.1 - DEFAULT_SLEEP_INTERVAL = 0.01 + DEFAULT_SLEEP_TIME = 2 + DEFAULT_SLEEP_INTERVAL = 0.2 class Cache(object): From c0373a715807457db92cf6e602ccc93580f6541f Mon Sep 17 00:00:00 2001 From: sebres Date: Thu, 22 Sep 2016 18:56:21 +0200 Subject: [PATCH 19/27] repair typo bug in reloading for systemd-filter; JailThread get method `join` for safe usage of it, also for not started threads (test-cases or in case of error), that will be used for cleanup resp. wait purposes also (see join of pyinotify-filter); --- fail2ban/server/filter.py | 10 +++++++--- fail2ban/server/filtergamin.py | 2 +- fail2ban/server/filterpoll.py | 4 +--- fail2ban/server/filterpyinotify.py | 17 ++++++++++++----- fail2ban/server/filtersystemd.py | 17 +++++++++++------ fail2ban/server/jail.py | 3 +-- fail2ban/server/jailthread.py | 15 +++++++++++++-- fail2ban/server/transmitter.py | 2 +- 8 files changed, 47 insertions(+), 23 deletions(-) diff --git a/fail2ban/server/filter.py b/fail2ban/server/filter.py index ac64fb86..13538c66 100644 --- a/fail2ban/server/filter.py +++ b/fail2ban/server/filter.py @@ -100,6 +100,10 @@ class Filter(JailThread): def __repr__(self): return "%s(%r)" % (self.__class__.__name__, self.jail) + @property + def jailName(self): + return (self.jail is not None and self.jail.name or "~jailless~") + def clearAllParams(self): """ Clear all lists/dicts parameters (used by reloading) """ @@ -135,7 +139,7 @@ class Filter(JailThread): if "\n" in regex.getRegex() and not self.getMaxLines() > 1: logSys.warning( "Mutliline regex set for jail %r " - "but maxlines not greater than 1", self.jail.name) + "but maxlines not greater than 1", self.jailName) except RegexException as e: logSys.error(e) raise e @@ -420,7 +424,7 @@ class Filter(JailThread): def logIgnoreIp(self, ip, log_ignore, ignore_source="unknown source"): if log_ignore: - logSys.info("[%s] Ignore %s by %s" % (self.jail.name, ip, ignore_source)) + logSys.info("[%s] Ignore %s by %s" % (self.jailName, ip, ignore_source)) def getIgnoreIP(self): return self.__ignoreIpList @@ -491,7 +495,7 @@ class Filter(JailThread): if self.inIgnoreIPList(ip, log_ignore=True): continue logSys.info( - "[%s] Found %s - %s", self.jail.name, ip, datetime.datetime.fromtimestamp(unixTime).strftime("%Y-%m-%d %H:%M:%S") + "[%s] Found %s - %s", self.jailName, ip, datetime.datetime.fromtimestamp(unixTime).strftime("%Y-%m-%d %H:%M:%S") ) tick = FailTicket(ip, unixTime, lines, data=fail) self.failManager.addFailure(tick) diff --git a/fail2ban/server/filtergamin.py b/fail2ban/server/filtergamin.py index a8d03ebd..106e4c0f 100644 --- a/fail2ban/server/filtergamin.py +++ b/fail2ban/server/filtergamin.py @@ -132,7 +132,7 @@ class FilterGamin(FileFilter): Utils.wait_for(lambda: not self.active or self._handleEvents(), self.sleeptime) self.ticks += 1 - logSys.debug(self.jail.name + ": filter terminated") + logSys.debug("[%s] filter terminated", self.jailName) return True def stop(self): diff --git a/fail2ban/server/filterpoll.py b/fail2ban/server/filterpoll.py index d0660f15..abf16e1b 100644 --- a/fail2ban/server/filterpoll.py +++ b/fail2ban/server/filterpoll.py @@ -123,9 +123,7 @@ class FilterPoll(FileFilter): except FailManagerEmpty: self.failManager.cleanup(MyTime.time()) self.__modified = False - logSys.debug( - (self.jail is not None and self.jail.name or "jailless") + - " filter terminated") + logSys.debug("[%s] filter terminated", self.jailName) return True ## diff --git a/fail2ban/server/filterpyinotify.py b/fail2ban/server/filterpyinotify.py index 9b444844..6ddf1691 100644 --- a/fail2ban/server/filterpyinotify.py +++ b/fail2ban/server/filterpyinotify.py @@ -198,7 +198,7 @@ class FilterPyinotify(FileFilter): prcevent, timeout=self.sleeptime) self.__notifier.check_events = self.__check_events self.__notifier.start() - logSys.debug("pyinotifier started for %s.", self.jail.name) + logSys.debug("[%s] filter started (pyinotifier)", self.jailName) return True ## @@ -206,15 +206,22 @@ class FilterPyinotify(FileFilter): def stop(self): super(FilterPyinotify, self).stop() - # Stop the notifier thread self.__notifier.stop() - self.__notifier.join() # to not exit before notifier does - self.__cleanup() # for pedantic ones + + ## + # Wait for exit with cleanup. + + def join(self): + self.__cleanup() + super(FilterPyinotify, self).join() + logSys.debug("[%s] filter terminated (pyinotifier)", self.jailName) ## # Deallocates the resources used by pyinotify. def __cleanup(self): - self.__notifier = None + if self.__notifier: + self.__notifier.join() # to not exit before notifier does + self.__notifier = None self.__monitor = None diff --git a/fail2ban/server/filtersystemd.py b/fail2ban/server/filtersystemd.py index a29085ba..310d15b3 100644 --- a/fail2ban/server/filtersystemd.py +++ b/fail2ban/server/filtersystemd.py @@ -130,7 +130,8 @@ class FilterSystemd(JournalFilter): # pragma: systemd no cover self.resetJournalMatches() raise else: - logSys.info("Added journal match for: %r", " ".join(match)) + logSys.info("[%s] Added journal match for: %r", self.jailName, + " ".join(match)) ## # Reset a journal match filter called on removal or failure # @@ -138,7 +139,7 @@ class FilterSystemd(JournalFilter): # pragma: systemd no cover def resetJournalMatches(self): self.__journal.flush_matches() - logSys.debug("Flushed all journal matches") + logSys.debug("[%s] Flushed all journal matches", self.jailName) match_copy = self.__matches[:] self.__matches = [] try: @@ -157,14 +158,17 @@ class FilterSystemd(JournalFilter): # pragma: systemd no cover def delJournalMatch(self, match=None): # clear all: if match is None: + if not self.__matches: + return del self.__matches[:] # delete by index: elif match in self.__matches: del self.__matches[self.__matches.index(match)] else: - raise ValueError("Match not found") + raise ValueError("Match %r not found" % match) self.resetJournalMatches() - logSys.info("Removed journal match for: %r" % " ".join(match)) + logSys.info("[%s] Removed journal match for: %r", self.jailName, + match if match else '*') ## # Get current journal match filter @@ -214,8 +218,8 @@ class FilterSystemd(JournalFilter): # pragma: systemd no cover date = logentry.get('_SOURCE_REALTIME_TIMESTAMP', logentry.get('__REALTIME_TIMESTAMP')) - logSys.debug("Read systemd journal entry: %r" % - "".join([date.isoformat(), logline])) + logSys.debug("[%s] Read systemd journal entry: %s %s", self.jailName, + date.isoformat(), logline) ## use the same type for 1st argument: return ((logline[:0], date.isoformat(), logline), time.mktime(date.timetuple()) + date.microsecond/1.0E6) @@ -302,6 +306,7 @@ class FilterSystemd(JournalFilter): # pragma: systemd no cover # incr common error counter: self.commonError() + logSys.debug("[%s] filter terminated", self.jailName) # close journal: try: if self.__journal: diff --git a/fail2ban/server/jail.py b/fail2ban/server/jail.py index aa4a38cc..39fdd959 100644 --- a/fail2ban/server/jail.py +++ b/fail2ban/server/jail.py @@ -257,8 +257,7 @@ class Jail(object): obj.stop() ## wait for end of threads: if join: - if obj.isAlive(): - obj.join() + obj.join() except Exception as e: logSys.error("Stop %r of jail %r failed: %s", obj, self.name, e, exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) diff --git a/fail2ban/server/jailthread.py b/fail2ban/server/jailthread.py index 39a86c2b..280b2171 100644 --- a/fail2ban/server/jailthread.py +++ b/fail2ban/server/jailthread.py @@ -53,8 +53,8 @@ class JailThread(Thread): super(JailThread, self).__init__(name=name) ## Should going with main thread also: self.daemon = True - ## Control the state of the thread. - self.active = False + ## Control the state of the thread (None - was not started, True - active, False - stopped). + self.active = None ## Control the idle state of the thread. self.idle = False ## The time the thread sleeps in the loop. @@ -93,3 +93,14 @@ class JailThread(Thread): """Abstract - Called when thread starts, thread stops when returns. """ pass + + def join(self): + """ Safer join, that could be called also for not started (or ended) threads (used for cleanup). + """ + ## if cleanup needed - create derivate and call it before join... + + ## if was really started - should call join: + if self.active is not None: + super(JailThread, self).join() + + diff --git a/fail2ban/server/transmitter.py b/fail2ban/server/transmitter.py index 19cf51ef..2f5be043 100644 --- a/fail2ban/server/transmitter.py +++ b/fail2ban/server/transmitter.py @@ -102,7 +102,7 @@ class Transmitter: self.__commandHandler(cmd) finally: self.__server.reloadJails(*opts, begin=False) - return None + return 'OK' elif len(command) >= 2 and command[0] == "unban": # unban in all jails: value = command[1:] From 48ebe3e73594ad43de7246eff36a509e6118e34b Mon Sep 17 00:00:00 2001 From: sebres Date: Thu, 22 Sep 2016 20:15:12 +0200 Subject: [PATCH 20/27] FilterPyinotify: high cpu load fix - timeout for pyinotify must be set in milliseconds (our time values are floats contain seconds); --- fail2ban/server/filterpyinotify.py | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/fail2ban/server/filterpyinotify.py b/fail2ban/server/filterpyinotify.py index 6ddf1691..56d6ef83 100644 --- a/fail2ban/server/filterpyinotify.py +++ b/fail2ban/server/filterpyinotify.py @@ -194,8 +194,9 @@ class FilterPyinotify(FileFilter): def run(self): prcevent = pyinotify.ProcessEvent() prcevent.process_default = self.__process_default + ## timeout for pyinotify must be set in milliseconds (our time values are floats contain seconds) self.__notifier = pyinotify.ThreadedNotifier(self.__monitor, - prcevent, timeout=self.sleeptime) + prcevent, timeout=self.sleeptime * 1000) self.__notifier.check_events = self.__check_events self.__notifier.start() logSys.debug("[%s] filter started (pyinotifier)", self.jailName) From ab0c28260bc91532bd576fd6bcb05301976e711a Mon Sep 17 00:00:00 2001 From: sebres Date: Thu, 22 Sep 2016 20:16:28 +0200 Subject: [PATCH 21/27] switch down log level for some annoying messages to tracedebug or heavydebug (to 7 or even 5); added verification of specified log-level before transmitting to the server; numeric log-level allowed now in server (resp. fail2ban.conf); --- fail2ban/__init__.py | 5 ++++- fail2ban/client/fail2banreader.py | 4 +++- fail2ban/helpers.py | 10 ++++++++++ fail2ban/protocol.py | 3 ++- fail2ban/server/filterpoll.py | 4 ++-- fail2ban/server/filterpyinotify.py | 2 +- fail2ban/server/filtersystemd.py | 2 +- fail2ban/server/server.py | 15 ++++++--------- fail2ban/tests/servertestcase.py | 2 ++ man/fail2ban-client.1 | 4 +++- man/fail2ban-regex.1 | 5 +++++ man/jail.conf.5 | 2 +- 12 files changed, 40 insertions(+), 18 deletions(-) diff --git a/fail2ban/__init__.py b/fail2ban/__init__.py index cd92dbab..0f0fc3ec 100644 --- a/fail2ban/__init__.py +++ b/fail2ban/__init__.py @@ -26,8 +26,11 @@ __license__ = "GPL" import logging.handlers -# Custom debug level +# Custom debug levels +logging.TRACEDEBUG = 7 logging.HEAVYDEBUG = 5 +logging.addLevelName(logging.TRACEDEBUG, 'TRACE') +logging.addLevelName(logging.HEAVYDEBUG, 'HEAVY') """ Below derived from: diff --git a/fail2ban/client/fail2banreader.py b/fail2ban/client/fail2banreader.py index 8e1b0e5c..c81d585e 100644 --- a/fail2ban/client/fail2banreader.py +++ b/fail2ban/client/fail2banreader.py @@ -25,7 +25,7 @@ __copyright__ = "Copyright (c) 2004 Cyril Jaquier" __license__ = "GPL" from .configreader import ConfigReader -from ..helpers import getLogger +from ..helpers import getLogger, str2LogLevel # Gets the instance of the logger. logSys = getLogger(__name__) @@ -58,6 +58,8 @@ class Fail2banReader(ConfigReader): self.__opts = ConfigReader.getOptions(self, "Definition", opts) if updateMainOpt: self.__opts.update(updateMainOpt) + # check given log-level: + str2LogLevel(self.__opts.get('loglevel', 0)) def convert(self): # Ensure logtarget/level set first so any db errors are captured diff --git a/fail2ban/helpers.py b/fail2ban/helpers.py index 2738f5e6..bbed61cf 100644 --- a/fail2ban/helpers.py +++ b/fail2ban/helpers.py @@ -129,6 +129,16 @@ def getLogger(name): name = "fail2ban.%s" % name.rpartition(".")[-1] return logging.getLogger(name) +def str2LogLevel(value): + try: + if isinstance(value, int) or value.isdigit(): + ll = int(value) + else: + ll = getattr(logging, value) + except AttributeError: + raise ValueError("Invalid log level %r" % value) + return ll + def excepthook(exctype, value, traceback): """Except hook used to log unhandled exceptions to Fail2Ban log diff --git a/fail2ban/protocol.py b/fail2ban/protocol.py index 879183e5..d1c33d88 100644 --- a/fail2ban/protocol.py +++ b/fail2ban/protocol.py @@ -61,7 +61,8 @@ protocol = [ ["help", "return this output"], ["version", "return the server version"], ['', "LOGGING", ""], -["set loglevel ", "sets logging level to . Levels: CRITICAL, ERROR, WARNING, NOTICE, INFO, DEBUG"], +["set loglevel ", "sets logging level to . Levels: CRITICAL, ERROR, WARNING, NOTICE, INFO, " + "DEBUG, TRACEDEBUG, HEAVYDEBUG or corresponding numeric value (50-5)"], ["get loglevel", "gets the logging level"], ["set logtarget ", "sets logging target to . Can be STDOUT, STDERR, SYSLOG or a file"], ["get logtarget", "gets logging target"], diff --git a/fail2ban/server/filterpoll.py b/fail2ban/server/filterpoll.py index abf16e1b..59310bed 100644 --- a/fail2ban/server/filterpoll.py +++ b/fail2ban/server/filterpoll.py @@ -137,10 +137,10 @@ class FilterPoll(FileFilter): logStats = os.stat(filename) stats = logStats.st_mtime, logStats.st_ino, logStats.st_size pstats = self.__prevStats.get(filename, (0)) - if logSys.getEffectiveLevel() <= 7: + if logSys.getEffectiveLevel() <= 5: # we do not want to waste time on strftime etc if not necessary dt = logStats.st_mtime - pstats[0] - logSys.log(7, "Checking %s for being modified. Previous/current stats: %s / %s. dt: %s", + logSys.log(5, "Checking %s for being modified. Previous/current stats: %s / %s. dt: %s", filename, pstats, stats, dt) # os.system("stat %s | grep Modify" % filename) self.__file404Cnt[filename] = 0 diff --git a/fail2ban/server/filterpyinotify.py b/fail2ban/server/filterpyinotify.py index 56d6ef83..73c82099 100644 --- a/fail2ban/server/filterpyinotify.py +++ b/fail2ban/server/filterpyinotify.py @@ -76,7 +76,7 @@ class FilterPyinotify(FileFilter): logSys.debug("Created FilterPyinotify") def callback(self, event, origin=''): - logSys.debug("%sCallback for Event: %s", origin, event) + logSys.log(7, "[%s] %sCallback for Event: %s", self.jailName, origin, event) path = event.pathname if event.mask & ( pyinotify.IN_CREATE | pyinotify.IN_MOVED_TO ): # skip directories altogether diff --git a/fail2ban/server/filtersystemd.py b/fail2ban/server/filtersystemd.py index 310d15b3..0d720a5e 100644 --- a/fail2ban/server/filtersystemd.py +++ b/fail2ban/server/filtersystemd.py @@ -218,7 +218,7 @@ class FilterSystemd(JournalFilter): # pragma: systemd no cover date = logentry.get('_SOURCE_REALTIME_TIMESTAMP', logentry.get('__REALTIME_TIMESTAMP')) - logSys.debug("[%s] Read systemd journal entry: %s %s", self.jailName, + logSys.log(5, "[%s] Read systemd journal entry: %s %s", self.jailName, date.isoformat(), logline) ## use the same type for 1st argument: return ((logline[:0], date.isoformat(), logline), diff --git a/fail2ban/server/server.py b/fail2ban/server/server.py index a21b1fce..2ae96e15 100644 --- a/fail2ban/server/server.py +++ b/fail2ban/server/server.py @@ -38,7 +38,7 @@ from .filter import FileFilter, JournalFilter from .transmitter import Transmitter from .asyncserver import AsyncServer, AsyncServerException from .. import version -from ..helpers import getLogger, excepthook +from ..helpers import getLogger, str2LogLevel, excepthook # Gets the instance of the logger. logSys = getLogger(__name__) @@ -510,14 +510,11 @@ class Server: with self.__loggingLock: if self.__logLevel == value: return - try: - ll = getattr(logging, value) - # don't change real log-level if running from the test cases: - getLogger("fail2ban").setLevel( - ll if DEF_LOGTARGET != "INHERITED" or ll < logging.DEBUG else DEF_LOGLEVEL) - self.__logLevel = value - except AttributeError: - raise ValueError("Invalid log level %r" % value) + ll = str2LogLevel(value) + # don't change real log-level if running from the test cases: + getLogger("fail2ban").setLevel( + ll if DEF_LOGTARGET != "INHERITED" or ll < logging.DEBUG else DEF_LOGLEVEL) + self.__logLevel = value ## # Get the logging level. diff --git a/fail2ban/tests/servertestcase.py b/fail2ban/tests/servertestcase.py index d044da4b..ebc39d9b 100644 --- a/fail2ban/tests/servertestcase.py +++ b/fail2ban/tests/servertestcase.py @@ -842,6 +842,8 @@ class TransmitterLogging(TransmitterBase): def testLogLevel(self): self.setGetTest("loglevel", "HEAVYDEBUG") + self.setGetTest("loglevel", "TRACEDEBUG") + self.setGetTest("loglevel", "9") self.setGetTest("loglevel", "DEBUG") self.setGetTest("loglevel", "INFO") self.setGetTest("loglevel", "NOTICE") diff --git a/man/fail2ban-client.1 b/man/fail2ban-client.1 index 33bce652..281d8f5b 100644 --- a/man/fail2ban-client.1 +++ b/man/fail2ban-client.1 @@ -120,7 +120,9 @@ LOGGING \fBset loglevel \fR sets logging level to . Levels: CRITICAL, ERROR, WARNING, -NOTICE, INFO, DEBUG +NOTICE, INFO, DEBUG, TRACEDEBUG, +HEAVYDEBUG or corresponding +numeric value (50\-5) .TP \fBget loglevel\fR gets the logging level diff --git a/man/fail2ban-regex.1 b/man/fail2ban-regex.1 index 342d18f7..44e13c86 100644 --- a/man/fail2ban-regex.1 +++ b/man/fail2ban-regex.1 @@ -51,6 +51,11 @@ File encoding. Default: system locale \fB\-r\fR, \fB\-\-raw\fR Raw hosts, don't resolve dns .TP +\fB\-\-usedns\fR=\fI\,USEDNS\/\fR +DNS specified replacement of tags in regexp +('yes' \- matches all form of hosts, 'no' \- IP +addresses only) +.TP \fB\-L\fR MAXLINES, \fB\-\-maxlines\fR=\fI\,MAXLINES\/\fR maxlines for multi\-line regex .TP diff --git a/man/jail.conf.5 b/man/jail.conf.5 index 865c689e..51a00cdc 100644 --- a/man/jail.conf.5 +++ b/man/jail.conf.5 @@ -127,7 +127,7 @@ These files have one section, [Definition]. The items that can be set are: .TP .B loglevel -verbosity level of log output: CRITICAL, ERROR, WARNING, NOTICE, INFO, DEBUG. Default: ERROR +verbosity level of log output: CRITICAL, ERROR, WARNING, NOTICE, INFO, DEBUG, TRACEDEBUG, HEAVYDEBUG or corresponding numeric value (50-5). Default: ERROR (equal 40) .TP .B logtarget log target: filename, SYSLOG, STDERR or STDOUT. Default: STDERR From e7fa74b98911abc52d9f2b6ee54e6dec0f6085ac Mon Sep 17 00:00:00 2001 From: sebres Date: Thu, 22 Sep 2016 21:32:39 +0200 Subject: [PATCH 22/27] smaller inertance inside test-cases (amend to d153555a07ec81dabe4678ea06c8e644afc8ec40 with decreasing default wait operation that litle bit speedup test-cases) --- fail2ban/tests/utils.py | 3 +++ 1 file changed, 3 insertions(+) diff --git a/fail2ban/tests/utils.py b/fail2ban/tests/utils.py index 76bb724c..91350b1d 100644 --- a/fail2ban/tests/utils.py +++ b/fail2ban/tests/utils.py @@ -243,6 +243,9 @@ def initTests(opts): raise unittest.SkipTest('Skip test because of "--fast"') unittest.F2B.SkipIfFast = F2B_SkipIfFast else: + # smaller inertance inside test-cases (litle speedup): + Utils.DEFAULT_SLEEP_TIME = 0.25 + Utils.DEFAULT_SLEEP_INTERVAL = 0.025 # sleep intervals are large - use replacement for sleep to check time to sleep: _org_sleep = time.sleep def _new_sleep(v): From e00be5f308c98a53bde277baa24d20b6712b9644 Mon Sep 17 00:00:00 2001 From: sebres Date: Thu, 22 Sep 2016 22:09:08 +0200 Subject: [PATCH 23/27] Fixed sporadically error in testCymruInfoNxdomain, because of unsorted values: ``` AssertionError: Dictionaries differ: {'country': ['unknown', 'nxdomain'], 'asn': ['4565', 'nxdomain'], 'rir': ['other', 'nxdomain']} != {'country': ['nxdomain', 'unknown'], 'asn': ['nxdomain', '4565'], 'rir': ['nxdomain', 'other']} ``` Added assertDictEqual for compatibility to early python versions (< 2.7); --- fail2ban/tests/banmanagertestcase.py | 13 ++++++------- fail2ban/tests/misctestcase.py | 4 ++++ fail2ban/tests/utils.py | 20 ++++++++++++++------ 3 files changed, 24 insertions(+), 13 deletions(-) diff --git a/fail2ban/tests/banmanagertestcase.py b/fail2ban/tests/banmanagertestcase.py index 4a86102c..de128b70 100644 --- a/fail2ban/tests/banmanagertestcase.py +++ b/fail2ban/tests/banmanagertestcase.py @@ -28,7 +28,6 @@ import unittest from ..server.banmanager import BanManager from ..server.ticket import BanTicket -from .utils import assert_dict_equal class AddFailure(unittest.TestCase): def setUp(self): @@ -131,7 +130,7 @@ class StatusExtendedCymruInfo(unittest.TestCase): def testCymruInfo(self): cymru_info = self.__banManager.getBanListExtendedCymruInfo() - assert_dict_equal(cymru_info, + self.assertDictEqual(cymru_info, {"asn": [self.__asn], "country": [self.__country], "rir": [self.__rir]}) @@ -158,7 +157,7 @@ class StatusExtendedCymruInfo(unittest.TestCase): ticket = BanTicket("0.0.0.0", 1167605999.0) self.assertTrue(self.__banManager.addBanTicket(ticket)) cymru_info = self.__banManager.getBanListExtendedCymruInfo() - assert_dict_equal(cymru_info, + self.assertDictEqual(cymru_info, {"asn": ["nxdomain"], "country": ["nxdomain"], "rir": ["nxdomain"]}) @@ -169,7 +168,7 @@ class StatusExtendedCymruInfo(unittest.TestCase): ticket = BanTicket("10.0.0.0", 1167606000.0) self.assertTrue(self.__banManager.addBanTicket(ticket)) cymru_info = self.__banManager.getBanListExtendedCymruInfo() - assert_dict_equal(cymru_info, - {"asn": ["nxdomain", "4565",], - "country": ["nxdomain", "unknown"], - "rir": ["nxdomain", "other"]}) + self.assertDictEqual(dict((k, sorted(v)) for k, v in cymru_info.iteritems()), + {"asn": sorted(["nxdomain", "4565",]), + "country": sorted(["nxdomain", "unknown"]), + "rir": sorted(["nxdomain", "other"])}) diff --git a/fail2ban/tests/misctestcase.py b/fail2ban/tests/misctestcase.py index 8fb393ea..450904d5 100644 --- a/fail2ban/tests/misctestcase.py +++ b/fail2ban/tests/misctestcase.py @@ -284,6 +284,10 @@ class TestsUtilsTest(LogCaptureTestCase): self.assertLogged, 'test_zyx', 'zyx', all=False) self._testAssertionErrorRE(r"All of the .* were found present in the log", self.assertNotLogged, 'test', 'xyz', all=False) + ## assertDictEqual: + self.assertDictEqual({'A': [1, 2]}, {'A': [1, 2]}) + self.assertRaises(AssertionError, self.assertDictEqual, + {'A': [1, 2]}, {'A': [2, 1]}) def testFormatterWithTraceBack(self): strout = StringIO() diff --git a/fail2ban/tests/utils.py b/fail2ban/tests/utils.py index 91350b1d..eecb94b8 100644 --- a/fail2ban/tests/utils.py +++ b/fail2ban/tests/utils.py @@ -466,6 +466,20 @@ def gatherTests(regexps=None, opts=None): # Forwards compatibility of unittest.TestCase for some early python versions # +if not hasattr(unittest.TestCase, 'assertDictEqual'): + import difflib, pprint + def assertDictEqual(self, d1, d2, msg=None): + self.assert_(isinstance(d1, dict), 'First argument is not a dictionary') + self.assert_(isinstance(d2, dict), 'Second argument is not a dictionary') + if d1 != d2: + standardMsg = '%r != %r' % (d1, d2) + diff = ('\n' + '\n'.join(difflib.ndiff( + pprint.pformat(d1).splitlines(), + pprint.pformat(d2).splitlines()))) + msg = msg or (standardMsg + diff) + self.fail(msg) + unittest.TestCase.assertDictEqual = assertDictEqual + if not hasattr(unittest.TestCase, 'assertRaisesRegexp'): def assertRaisesRegexp(self, exccls, regexp, fun, *args, **kwargs): try: @@ -673,9 +687,3 @@ class LogCaptureTestCase(unittest.TestCase): pid_exists = Utils.pid_exists - -# Python 2.6 compatibility. in 2.7 assertDictEqual -def assert_dict_equal(a, b): - assert isinstance(a, dict), "Object is not dictionary: %r" % a - assert isinstance(b, dict), "Object is not dictionary: %r" % b - assert a==b, "Dictionaries differ:\n%r !=\n%r" % (a, b) From 004879b5b15c8d404a22935bfd0c41579faf3d87 Mon Sep 17 00:00:00 2001 From: sebres Date: Fri, 23 Sep 2016 09:32:10 +0200 Subject: [PATCH 24/27] code review: switch MAX_TIME to 0X7FFFFFFFFFFF (is enough, because 4461763-th year, but better performance) --- fail2ban/server/banmanager.py | 4 ++-- fail2ban/server/ticket.py | 4 +++- 2 files changed, 5 insertions(+), 3 deletions(-) diff --git a/fail2ban/server/banmanager.py b/fail2ban/server/banmanager.py index 6da5366c..9aa69f5a 100644 --- a/fail2ban/server/banmanager.py +++ b/fail2ban/server/banmanager.py @@ -57,7 +57,7 @@ class BanManager: ## Total number of banned IP address self.__banTotal = 0 ## The time for next unban process (for performance and load reasons): - self.__nextUnbanTime = 0xFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFL + self.__nextUnbanTime = BanTicket.MAX_TIME ## # Set the ban time. @@ -322,7 +322,7 @@ class BanManager: # Gets the list of ticket to remove (thereby correct next unban time). unBanList = {} - self.__nextUnbanTime = 0xFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFL + self.__nextUnbanTime = BanTicket.MAX_TIME for fid,ticket in self.__banList.iteritems(): # current time greater as end of ban - timed out: eob = ticket.getEndOfBanTime(self.__banTime) diff --git a/fail2ban/server/ticket.py b/fail2ban/server/ticket.py index 2f9a88ed..c7bb4d47 100644 --- a/fail2ban/server/ticket.py +++ b/fail2ban/server/ticket.py @@ -35,6 +35,8 @@ logSys = getLogger(__name__) class Ticket(object): + + MAX_TIME = 0X7FFFFFFFFFFF ;# 4461763-th year RESTORED = 0x01 BANNED = 0x08 @@ -112,7 +114,7 @@ class Ticket(object): bantime = (self._banTime if self._banTime is not None else defaultBT) # permanent if bantime == -1: - return 0xFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFL + return Ticket.MAX_TIME # unban time (end of ban): return self._time + bantime From 449c46aec45a39e6406894f77ee965a6322bcb1e Mon Sep 17 00:00:00 2001 From: sebres Date: Fri, 23 Sep 2016 15:21:23 +0200 Subject: [PATCH 25/27] extended test-cases (coverage) --- fail2ban/tests/banmanagertestcase.py | 21 ++++++++++++++++++++- 1 file changed, 20 insertions(+), 1 deletion(-) diff --git a/fail2ban/tests/banmanagertestcase.py b/fail2ban/tests/banmanagertestcase.py index de128b70..b627599d 100644 --- a/fail2ban/tests/banmanagertestcase.py +++ b/fail2ban/tests/banmanagertestcase.py @@ -95,9 +95,28 @@ class AddFailure(unittest.TestCase): def testUnban(self): btime = self.__banManager.getBanTime() + stime = self.__ticket.getTime() self.assertTrue(self.__banManager.addBanTicket(self.__ticket)) self.assertTrue(self.__banManager._inBanList(self.__ticket)) - self.assertEqual(self.__banManager.unBanList(self.__ticket.getTime() + btime + 1), [self.__ticket]) + self.assertEqual(self.__banManager.unBanList(stime), []) + self.assertEqual(self.__banManager.unBanList(stime + btime + 1), [self.__ticket]) + self.assertEqual(self.__banManager.size(), 0) + ## again, but now we will prolong ban-time and then try to unban again (1st too early): + self.assertTrue(self.__banManager.addBanTicket(self.__ticket)) + # prolong ban: + ticket = BanTicket(self.__ticket.getID(), stime + 600) + self.assertFalse(self.__banManager.addBanTicket(ticket)) + # try unban too early: + self.assertEqual(len(self.__banManager.unBanList(stime + btime + 1)), 0) + # try unban using correct time: + self.assertEqual(len(self.__banManager.unBanList(stime + btime + 600 + 1)), 1) + ## again, but now we test removing tickets particular (to test < 2/3-rule): + for i in range(5): + ticket = BanTicket('193.168.0.%s' % i, stime) + ticket.setBanTime(ticket.getBanTime(btime) + i*10) + self.assertTrue(self.__banManager.addBanTicket(ticket)) + self.assertEqual(len(self.__banManager.unBanList(stime + btime + 1*10 + 1)), 2) + self.assertEqual(len(self.__banManager.unBanList(stime + btime + 5*10 + 1)), 3) self.assertEqual(self.__banManager.size(), 0) def testUnbanPermanent(self): From 5e4fdb60c8a415dcf0c702a8ee2896cd25d5550d Mon Sep 17 00:00:00 2001 From: sebres Date: Mon, 26 Sep 2016 10:50:02 +0200 Subject: [PATCH 26/27] extended test-cases (coverage) --- fail2ban/server/database.py | 2 +- fail2ban/tests/databasetestcase.py | 5 +++++ 2 files changed, 6 insertions(+), 1 deletion(-) diff --git a/fail2ban/server/database.py b/fail2ban/server/database.py index 120619f9..77786f57 100644 --- a/fail2ban/server/database.py +++ b/fail2ban/server/database.py @@ -211,7 +211,7 @@ class Fail2BanDb(object): if newversion == Fail2BanDb.__version__: logSys.warning( "Database updated from '%i' to '%i'", version, newversion) - else: + else: # pragma: no cover logSys.error( "Database update failed to achieve version '%i'" ": updated from '%i' to '%i'", Fail2BanDb.__version__, version, newversion) diff --git a/fail2ban/tests/databasetestcase.py b/fail2ban/tests/databasetestcase.py index 02d2c79b..b1c68a8f 100644 --- a/fail2ban/tests/databasetestcase.py +++ b/fail2ban/tests/databasetestcase.py @@ -353,6 +353,11 @@ class DatabaseTest(LogCaptureTestCase): # be returned tickets = self.db.getBansMerged(bantime=-1) self.assertEqual(len(tickets), 2) + # getCurrentBans: + tickets = self.db.getCurrentBans(jail=self.jail) + self.assertEqual(len(tickets), 2) + ticket = self.db.getCurrentBans(jail=None, ip="127.0.0.1"); + self.assertEqual(ticket.getIP(), "127.0.0.1") def testActionWithDB(self): # test action together with database functionality From 5151c4fa6d36dd0e1569a2a8fbb0a797d3f7bb9a Mon Sep 17 00:00:00 2001 From: sebres Date: Mon, 26 Sep 2016 11:15:59 +0200 Subject: [PATCH 27/27] ChangeLog entries added --- ChangeLog | 85 +++++++++++++++++++++++++++++++++++++++++++++++-------- 1 file changed, 73 insertions(+), 12 deletions(-) diff --git a/ChangeLog b/ChangeLog index 204c9559..0c1c3676 100644 --- a/ChangeLog +++ b/ChangeLog @@ -12,14 +12,22 @@ ver. 0.10.0 (2016/XX/XXX) - gonna-be-released-some-time-shining TODO: implementing of options resp. other tasks from PR #1346 ### Fixes -* [grave] memory leak's fixed (gh-1277, gh-1234) -* tricky bug fix: last position of log file will be never retrieved (gh-795), +* [Grave] memory leak's fixed (gh-1277, gh-1234) +* Tricky bug fix: last position of log file will be never retrieved (gh-795), because of CASCADE all log entries will be deleted from logs table together with jail, if used "INSERT OR REPLACE" statement -* asyncserver (asyncore) code fixed and test cases repaired (again gh-161) +* Asyncserver (asyncore) code fixed and test cases repaired (again gh-161) * 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) +* Fixed high-load of pyinotify-backend, + see https://github.com/fail2ban/fail2ban/issues/885#issuecomment-248964591 +* Database: stability fix - repack cursor iterator as long as locked +* File filter backends: stability fix for sporadically errors - always close file + handle, otherwise may be locked (prevent log-rotate, etc.) +* Pyinotify-backend: stability fix for sporadically errors in multi-threaded + environment (without lock) +* Fixed sporadically error in testCymruInfoNxdomain, because of unsorted values ### New Features * IPv6 support: @@ -33,18 +41,33 @@ 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 +* New reload functionality (now totally without restart, unbanning/rebanning, etc.), + see gh-1557 +* Several commands extended and new commands introduced: + - `restart [--unban] [--if-exists] ` - restarts the jail \ + (alias for `reload --restart ... `) + - `reload [--restart] [--unban] [--all]` - reloads the configuration without restarting + of the server, the option `--restart` activates completely restarting of affected jails, + thereby can unban IP addresses (if option `--unban` specified) + - `reload [--restart] [--unban] [--if-exists] ` - reloads the jail \, + or restarts it (if option `--restart` specified), at the same time unbans all IP addresses + banned in this jail, if option `--unban` specified + - `unban --all` - unbans all IP addresses (in all jails and database) + - `unban ... ` - unbans \ (in all jails and database) (see gh-1388) +* New command action parameter `actionrepair` - command executed in order to restore + sane environment in error case of `actioncheck`. ### Enhancements -* huge increasing of fail2ban performance and especially test-cases performance (see gh-1109) -* datedetector: in-place reordering using hits and last used time: +* Huge increasing of fail2ban performance and especially test-cases performance (see gh-1109) +* Datedetector: in-place reordering using hits and last used time: matchTime, template list etc. rewritten because of performance degradation -* prevent out of memory situation if many IP's makes extremely many failures (maxEntries) -* introduced string to seconds (str2seconds) for configuration entries with time, +* Prevent out of memory situation if many IP's makes extremely many failures (maxEntries) +* Introduced string to seconds (str2seconds) for configuration entries with time, use `1h` instead of `3600`, `1d` instead of `86400`, etc * seekToTime - prevent completely read of big files first time (after start of service), initial seek to start time using half-interval search algorithm (see issue gh-795) -* ticket and some other modules prepared to easy merge with newest version of 'ban-time-incr' -* cache dnsToIp, ipToName to prevent long wait during retrieving of ip/name, +* Ticket and some other modules prepared to easy merge with newest version of 'ban-time-incr' +* Cache dnsToIp, ipToName to prevent long wait during retrieving of ip/name, especially for wrong dns or lazy dns-system * FailManager memory-optimization: increases performance, prevents memory leakage, because don't copy failures list on some operations @@ -54,14 +77,52 @@ TODO: implementing of options resp. other tasks from PR #1346 - `-g`, `--no-gamin` to prevent running of tests that require the gamin (slow) - `-m`, `--memory-db` - run database tests using memory instead of file - `-i`, `--ignore` - negate [regexps] filter to ignore tests matched specified regexps -* background servicing: prevents memory leak on some platforms/python versions, using forced GC +* Background servicing: prevents memory leak on some platforms/python versions, using forced GC in periodic intervals (latency and threshold) * executeCmd partially moved from action to new module utils -* several functionality of class `DNSUtils` moved to new class `IPAddr`, +* Several functionality of class `DNSUtils` moved to new class `IPAddr`, both classes moved to new module `ipdns` -* pseudo-conditional section introduced, for conditional substitution resp. +* Pseudo-conditional section introduced, for conditional substitution resp. evaluation of parameters for different family qualified hosts, syntax `[Section?family=inet6]` (currently use for IPv6-support only). +* All the backends were rewritten to get reload-possibility, performance increased, + so fewer greedy regarding cpu- resp. system-load now +* Numeric log-level allowed now in server (resp. fail2ban.conf); +* Implemented better error handling in some multi-threaded routines; shutdown of jails + rewritten (faster and safer, does not breaks shutdown process if some error occurred) +* Possibility for overwriting some configuration options (read with config-readers) + with command line option, e. g.: +```bash +## start server with DEBUG log-level (ignore level read from fail2ban.conf): +fail2ban-client --loglevel DEBUG start +## or +fail2ban-server -c /cfg/path --loglevel DEBUG start +## keep server log-level by reload (without restart it) +fail2ban-client --loglevel DEBUG reload +## switch log-level back to INFO: +fail2ban-client set loglevel INFO +``` +* Optimized BanManager: increase performance, fewer system load, try to prevent + memory leakage: + - better ban/unban handling within actions (e.g. used dict instead of list) + - don't copy bans resp. its list on some operations; + - added new unbantime handling to relieve unBanList (prevent permanent + searching for tickets to unban) + - prefer failure-ID as identifier of the ticket to its IP (most of the time + the same, but it can be something else e.g. user name in some complex jails, + as introduced in 0.10) +* Regexp enhancements: + - build replacement of `` substitution corresponding parameter + `usedns` - dns-part will be added only if `usedns` is not `no`, + also using fail2ban-regex + - new replacement for `` in opposition to ``, for separate + usage of 2 address groups only (regardless of `usedns`), `ip4` and `ip6` + together, without host (dns) +* fail2ban-testcases: + - `assertLogged` extended with parameter wait (to wait up to specified timeout, + before we throw assert exception) + test cases rewritten using that + - added `assertDictEqual` for compatibility to early python versions (< 2.7); + - new `with_foreground_server_thread` decorator to test several client/server commands ver. 0.9.6 (2016/XX/XX) - wanna-be-released