From 8f3671bc94c604ae33a7592d0e72220cbc00dd52 Mon Sep 17 00:00:00 2001 From: Yaroslav Halchenko Date: Tue, 2 Jul 2013 17:10:00 -0400 Subject: [PATCH 01/13] BF: figure out minimal sleep time needed for mtime changes to get detected. Close #223, and probably #103 --- testcases/filtertestcase.py | 22 +++++----------- testcases/utils.py | 50 ++++++++++++++++++++++++++++++++++++- 2 files changed, 55 insertions(+), 17 deletions(-) diff --git a/testcases/filtertestcase.py b/testcases/filtertestcase.py index 1657f694..2381c942 100644 --- a/testcases/filtertestcase.py +++ b/testcases/filtertestcase.py @@ -39,6 +39,8 @@ from server.failmanager import FailManagerEmpty # Useful helpers # +from utils import mtimesleep + # yoh: per Steven Hiscocks's insight while troubleshooting # https://github.com/fail2ban/fail2ban/issues/103#issuecomment-15542836 # adding a sufficiently large buffer might help to guarantee that @@ -68,18 +70,6 @@ def _killfile(f, name): _killfile(None, name + '.bak') -def _sleep_4_poll(): - """PollFilter relies on file timestamps - so we might need to - sleep to guarantee that they differ - """ - if sys.version_info[:2] <= (2,4): - # on old Python st_mtime is int, so we should give - # at least 1 sec so polling filter could detect - # the change - time.sleep(1.) - else: - time.sleep(0.1) - def _assert_equal_entries(utest, found, output, count=None): """Little helper to unify comparisons with the target entries @@ -237,14 +227,14 @@ class LogFileMonitor(unittest.TestCase): # but not any longer self.assertTrue(self.notModified()) self.assertTrue(self.notModified()) - _sleep_4_poll() # to guarantee freshier mtime + mtimesleep() # to guarantee freshier mtime for i in range(4): # few changes # unless we write into it self.file.write("line%d\n" % i) self.file.flush() self.assertTrue(self.isModified()) self.assertTrue(self.notModified()) - _sleep_4_poll() # to guarantee freshier mtime + mtimesleep() # to guarantee freshier mtime os.rename(self.name, self.name + '.old') # we are not signaling as modified whenever # it gets away @@ -252,7 +242,7 @@ class LogFileMonitor(unittest.TestCase): f = open(self.name, 'a') self.assertTrue(self.isModified()) self.assertTrue(self.notModified()) - _sleep_4_poll() + mtimesleep() f.write("line%d\n" % i) f.flush() self.assertTrue(self.isModified()) @@ -398,7 +388,7 @@ def get_monitor_failures_testcase(Filter_): # actions might be happening too fast in the tests, # sleep a bit to guarantee reliable time stamps if isinstance(self.filter, FilterPoll): - _sleep_4_poll() + mtimesleep() def isEmpty(self, delay=0.4): # shorter wait time for not modified status diff --git a/testcases/utils.py b/testcases/utils.py index 87aab915..b8d467bf 100644 --- a/testcases/utils.py +++ b/testcases/utils.py @@ -22,7 +22,7 @@ __author__ = "Yaroslav Halchenko" __copyright__ = "Copyright (c) 2013 Yaroslav Halchenko" __license__ = "GPL" -import logging, os, re, traceback +import logging, os, re, tempfile, sys, time, traceback from os.path import basename, dirname # @@ -100,3 +100,51 @@ class FormatterWithTraceBack(logging.Formatter): def format(self, record): record.tbc = record.tb = self._tb() return logging.Formatter.format(self, record) + + +class MTimeSleep(object): + """Sleep minimal duration needed to resolve changes in mtime of files in TMPDIR + + mtime resolution depends on Python version AND underlying filesystem + """ + def __init__(self): + self._sleep = None + + @staticmethod + def _get_good_sleep(): + times = [1., 2., 5., 10.] + # we know that older Pythons simply have no ability to resolve + # at < sec level. + if sys.version_info[:2] > (2, 4): + times = [0.01, 0.1] + times + ffid, name = tempfile.mkstemp() + tfile = os.fdopen(ffid, 'w') + + for stime in times: + prev_stat, dt = "", 0. + # needs to be done 3 times (not clear why) + for i in xrange(3): + stat2 = os.stat(name) + if prev_stat: + dt = (stat2.st_mtime - prev_stat.st_mtime) + prev_stat = stat2 + tfile.write("LOAD\n") + tfile.flush() + time.sleep(stime) + if dt: + break + if not dt: + import logging + logSys = logging.getLogger("fail2ban.tests") + #from warnings import warn + logSys.warn("Could not deduce appropriate sleep time for tests. " + "Maximal tested one of %f sec will be used." % stime) + os.unlink(name) + return stime + + def __call__(self): + if self._sleep is None: + self._sleep = self._get_good_sleep() + time.sleep(self._sleep) + +mtimesleep = MTimeSleep() From 591590860ac3077d9ec24af3c0f998df15820541 Mon Sep 17 00:00:00 2001 From: Yaroslav Halchenko Date: Tue, 2 Jul 2013 17:11:24 -0400 Subject: [PATCH 02/13] BF: setSleepTime -- would barf since value is not str (wasn't used/tested) --- server/jailthread.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/server/jailthread.py b/server/jailthread.py index 11d1a82b..ca6effae 100644 --- a/server/jailthread.py +++ b/server/jailthread.py @@ -56,7 +56,7 @@ class JailThread(Thread): def setSleepTime(self, value): self.__sleepTime = value - logSys.info("Set sleeptime = " + value) + logSys.info("Set sleeptime %s" % value) ## # Get the time that the thread sleeps. From e9c8a51ce492d2ee225e514395642f50ae8a64d6 Mon Sep 17 00:00:00 2001 From: Yaroslav Halchenko Date: Tue, 2 Jul 2013 17:26:41 -0400 Subject: [PATCH 03/13] ENH: further tighten up detection of mtimesleep duration + log what was assigned --- testcases/utils.py | 18 ++++++++++++------ 1 file changed, 12 insertions(+), 6 deletions(-) diff --git a/testcases/utils.py b/testcases/utils.py index b8d467bf..6107516b 100644 --- a/testcases/utils.py +++ b/testcases/utils.py @@ -112,11 +112,12 @@ class MTimeSleep(object): @staticmethod def _get_good_sleep(): - times = [1., 2., 5., 10.] + logSys = logging.getLogger("fail2ban.tests") + times = [1.5, 2., 5., 10.] # we know that older Pythons simply have no ability to resolve # at < sec level. if sys.version_info[:2] > (2, 4): - times = [0.01, 0.1] + times + times = [0.1] + times ffid, name = tempfile.mkstemp() tfile = os.fdopen(ffid, 'w') @@ -131,14 +132,19 @@ class MTimeSleep(object): tfile.write("LOAD\n") tfile.flush() time.sleep(stime) - if dt: - break + + # check dt but also verify that we are not getting 'quick' + # stime simply by chance of catching second increment + if dt and \ + not (stime < 1 and int(stat2.st_mtime) == stat2.st_mtime): + break if not dt: - import logging - logSys = logging.getLogger("fail2ban.tests") #from warnings import warn logSys.warn("Could not deduce appropriate sleep time for tests. " "Maximal tested one of %f sec will be used." % stime) + else: + logSys.debug("It was needed a sleep of %f to detect dt=%f mtime change" + % (stime, dt)) os.unlink(name) return stime From 2ffc14359722acff7ddb19f4f1758dab69fb6f8e Mon Sep 17 00:00:00 2001 From: Yaroslav Halchenko Date: Tue, 2 Jul 2013 19:49:41 -0400 Subject: [PATCH 04/13] ENH: more of heavydebug'ing for FilterPoll --- server/filterpoll.py | 14 ++++++++++++++ 1 file changed, 14 insertions(+) diff --git a/server/filterpoll.py b/server/filterpoll.py index 20cde0ca..4acecd42 100644 --- a/server/filterpoll.py +++ b/server/filterpoll.py @@ -30,6 +30,11 @@ from mytime import MyTime import time, logging, os +def _ctime(t): + """Given time in seconds provide string representation with milliseconds + """ + return "%s%.3f" %(time.strftime("%X", time.localtime(t)), (t-int(t))) + # Gets the instance of the logger. logSys = logging.getLogger("fail2ban.filter") @@ -84,6 +89,9 @@ class FilterPoll(FileFilter): def run(self): self.setActive(True) while self._isActive(): + if logSys.getEffectiveLevel() <= 6: + logSys.log(6, "Woke up idle=%s with %d files monitored", + self.getIdle(), len(self.getLogPath())) if not self.getIdle(): # Get file modification for container in self.getLogPath(): @@ -119,6 +127,12 @@ class FilterPoll(FileFilter): try: logStats = os.stat(filename) self.__file404Cnt[filename] = 0 + if logSys.getEffectiveLevel() <= 7: + # we do not want to waste time on strftime etc if not necessary + dt = logStats.st_mtime - self.__lastModTime[filename] + logSys.log(7, "Checking %s for being modified. Previous/current mtimes: %s / %s. dt: %s", + filename, _ctime(self.__lastModTime[filename]), _ctime(logStats.st_mtime), dt) + # os.system("stat %s | grep Modify" % filename) if self.__lastModTime[filename] == logStats.st_mtime: return False else: From 8c125b6053d137132bacfa7c25cb84e261cd9894 Mon Sep 17 00:00:00 2001 From: Yaroslav Halchenko Date: Tue, 2 Jul 2013 19:50:22 -0400 Subject: [PATCH 05/13] ENH: do not sleep 1 sec only on older Pythons while testing filters --- testcases/filtertestcase.py | 7 +++---- 1 file changed, 3 insertions(+), 4 deletions(-) diff --git a/testcases/filtertestcase.py b/testcases/filtertestcase.py index 2381c942..f2f6eb50 100644 --- a/testcases/filtertestcase.py +++ b/testcases/filtertestcase.py @@ -109,10 +109,9 @@ def _copy_lines_between_files(fin, fout, n=None, skip=0, mode='a', terminal_line Returns open fout """ - if sys.version_info[:2] <= (2,4): # pragma: no cover - # on old Python st_mtime is int, so we should give at least 1 sec so - # polling filter could detect the change - time.sleep(1) + # on older Pythons and on some FSs st_mtime is int, so we should + # give it some time so polling filter could detect the change + mtimesleep() if isinstance(fin, str): # pragma: no branch - only used with str in test cases fin = open(fin, 'r') # Skip From f340e5c0f5a74a6bb0b515d9e25dec57f28467c6 Mon Sep 17 00:00:00 2001 From: Yaroslav Halchenko Date: Tue, 2 Jul 2013 20:43:51 -0400 Subject: [PATCH 06/13] ENH(+possibly BF): for FilterPoll rely not only on mtime but also ino and size to assess if file was modified mtime alone is a poor measure here as many of our tests shown -- on older Pythons and some file systems mtime might be reported only with precision up to a second. If file gets rotated fast, or there are new modifications within the same second, fail2ban might miss them with Polling backend if judging only by mtime. With this modification we will track also inode and size which are all indicative of a file change. --- server/filterpoll.py | 20 +++++++++++--------- 1 file changed, 11 insertions(+), 9 deletions(-) diff --git a/server/filterpoll.py b/server/filterpoll.py index 4acecd42..4cd7cb48 100644 --- a/server/filterpoll.py +++ b/server/filterpoll.py @@ -57,7 +57,7 @@ class FilterPoll(FileFilter): FileFilter.__init__(self, jail) self.__modified = False ## The time of the last modification of the file. - self.__lastModTime = dict() + self.__prevStats = dict() self.__file404Cnt = dict() logSys.debug("Created FilterPoll") @@ -67,7 +67,7 @@ class FilterPoll(FileFilter): # @param path log file path def _addLogPath(self, path): - self.__lastModTime[path] = 0 + self.__prevStats[path] = (0, None, None) # mtime, ino, size self.__file404Cnt[path] = 0 ## @@ -76,7 +76,7 @@ class FilterPoll(FileFilter): # @param path the log file to delete def _delLogPath(self, path): - del self.__lastModTime[path] + del self.__prevStats[path] del self.__file404Cnt[path] ## @@ -126,18 +126,20 @@ class FilterPoll(FileFilter): def isModified(self, filename): try: logStats = os.stat(filename) + stats = logStats.st_mtime, logStats.st_ino, logStats.st_size + pstats = self.__prevStats[filename] self.__file404Cnt[filename] = 0 if logSys.getEffectiveLevel() <= 7: # we do not want to waste time on strftime etc if not necessary - dt = logStats.st_mtime - self.__lastModTime[filename] - logSys.log(7, "Checking %s for being modified. Previous/current mtimes: %s / %s. dt: %s", - filename, _ctime(self.__lastModTime[filename]), _ctime(logStats.st_mtime), dt) + 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) - if self.__lastModTime[filename] == logStats.st_mtime: + if pstats == stats: return False else: - logSys.debug(filename + " has been modified") - self.__lastModTime[filename] = logStats.st_mtime + logSys.debug("%s has been modified", filename) + self.__prevStats[filename] = stats return True except OSError, e: logSys.error("Unable to get stat on %s because of: %s" From 052e7ff9da53865a38c28631a6857112ad21bbad Mon Sep 17 00:00:00 2001 From: Yaroslav Halchenko Date: Tue, 2 Jul 2013 20:44:28 -0400 Subject: [PATCH 07/13] ENH: deprecate sophisticated MTimeSleep in favor of no sleeping at all all invocations of mtimesleep() are left in the tests for now --- testcases/utils.py | 57 ++++------------------------------------------ 1 file changed, 4 insertions(+), 53 deletions(-) diff --git a/testcases/utils.py b/testcases/utils.py index 6107516b..643c9ad1 100644 --- a/testcases/utils.py +++ b/testcases/utils.py @@ -101,56 +101,7 @@ class FormatterWithTraceBack(logging.Formatter): record.tbc = record.tb = self._tb() return logging.Formatter.format(self, record) - -class MTimeSleep(object): - """Sleep minimal duration needed to resolve changes in mtime of files in TMPDIR - - mtime resolution depends on Python version AND underlying filesystem - """ - def __init__(self): - self._sleep = None - - @staticmethod - def _get_good_sleep(): - logSys = logging.getLogger("fail2ban.tests") - times = [1.5, 2., 5., 10.] - # we know that older Pythons simply have no ability to resolve - # at < sec level. - if sys.version_info[:2] > (2, 4): - times = [0.1] + times - ffid, name = tempfile.mkstemp() - tfile = os.fdopen(ffid, 'w') - - for stime in times: - prev_stat, dt = "", 0. - # needs to be done 3 times (not clear why) - for i in xrange(3): - stat2 = os.stat(name) - if prev_stat: - dt = (stat2.st_mtime - prev_stat.st_mtime) - prev_stat = stat2 - tfile.write("LOAD\n") - tfile.flush() - time.sleep(stime) - - # check dt but also verify that we are not getting 'quick' - # stime simply by chance of catching second increment - if dt and \ - not (stime < 1 and int(stat2.st_mtime) == stat2.st_mtime): - break - if not dt: - #from warnings import warn - logSys.warn("Could not deduce appropriate sleep time for tests. " - "Maximal tested one of %f sec will be used." % stime) - else: - logSys.debug("It was needed a sleep of %f to detect dt=%f mtime change" - % (stime, dt)) - os.unlink(name) - return stime - - def __call__(self): - if self._sleep is None: - self._sleep = self._get_good_sleep() - time.sleep(self._sleep) - -mtimesleep = MTimeSleep() +def mtimesleep(): + # no sleep now should be necessary since polling tracks now not only + # mtime but also ino and size + pass From 8d25e83f5d154fd2adcaa3cac5f883a8f87b56ad Mon Sep 17 00:00:00 2001 From: Yaroslav Halchenko Date: Tue, 2 Jul 2013 23:37:23 -0400 Subject: [PATCH 08/13] BF: race condition -- file should not be read unless it is not empty Previous code would store md5sum of an empty line as the one identifying the monitored file. That file then was read and possibly failures were found. Upon next "container.open()", md5 digest of now present first line was compared against previous digest of an empty line, which was different, thus file was assumed to be rotated and all the log lines were read once again. The History ----------- In rare cases various tests failed somewhat consistently. Below you can find one case in test_move_file where such failure really made no sense -- we should have not had 4 failures by that point. Fail2ban 0.8.10.dev test suite. Python 2.4.6 (#2, Sep 25 2009, 22:22:06) [GCC 4.3.4]. Please wait... I: Skipping gamin backend testing. Got exception 'No module named gamin' I: Skipping pyinotify backend testing. Got exception 'No module named pyinotify' D: fn=/home/yoh/test/monitorfailures_FilterPoll9nUKoCfail2ban-0 hashes=d41d8cd98f00b204e9800998ecf8427e/d41d8cd98f00b204e9800998ecf8427e inos=5398862/5398862 pos=0 rotate=False D: Adding a ticket for ('193.168.0.128', 1124013599.0, ['Aug 14 11:59:59 [sshd] error: PAM: Authentication failure for kevin from 193.168.0.128\n']) D: Adding a ticket for ('193.168.0.128', 1124013599.0, ['Aug 14 11:59:59 [sshd] error: PAM: Authentication failure for kevin from 193.168.0.128\n']) D: Closed with pos 1231 D: fn=/home/yoh/test/monitorfailures_FilterPoll9nUKoCfail2ban-0 hashes=d41d8cd98f00b204e9800998ecf8427e/aeb4e73e6922a746d027eb365ece2149 inos=5398862/5398862 pos=1231 rotate=True D: Adding a ticket for ('193.168.0.128', 1124013599.0, ['Aug 14 11:59:59 [sshd] error: PAM: Authentication failure for kevin from 193.168.0.128\n']) D: Adding a ticket for ('193.168.0.128', 1124013599.0, ['Aug 14 11:59:59 [sshd] error: PAM: Authentication failure for kevin from 193.168.0.128\n']) D: Closed with pos 1231 F ====================================================================== FAIL: test_move_file (testcases.filtertestcase.MonitorFailures(/home/yoh/test/monitorfailures_FilterPoll9nUKoCfail2ban)) ---------------------------------------------------------------------- Traceback (most recent call last): File "/home/yoh/deb/gits/fail2ban/testcases/filtertestcase.py", line 451, in test_move_file "Queue must be empty but it is not: %s." AssertionError: Queue must be empty but it is not: server.ticket.FailTicket: ip=193.168.0.128 time=1124013599.0 #attempts=4. ---------------------------------------------------------------------- N.B.1 I preserved here and in the code corresponding additional debug print statements, which are commented out by default. sensible md5 digest was generated by using hexdigest() instead of current a bit faster digest(). Running tests with all the debug output simply breaks the race loose and failure doesn't trigger. N.B.2 d41d8cd98f00b204e9800998ecf8427e is an md5sum of an empty string, and aeb4e73e6922a746d027eb365ece2149 of the first line in that file. --- server/filter.py | 27 ++++++++++++++++++++++++--- 1 file changed, 24 insertions(+), 3 deletions(-) diff --git a/server/filter.py b/server/filter.py index 59e612ed..b7c2d091 100644 --- a/server/filter.py +++ b/server/filter.py @@ -21,6 +21,8 @@ __author__ = "Cyril Jaquier and Fail2Ban Contributors" __copyright__ = "Copyright (c) 2004 Cyril Jaquier, 2011-2013 Yaroslav Halchenko" __license__ = "GPL" +import sys + from failmanager import FailManagerEmpty from failmanager import FailManager from ticket import FailTicket @@ -322,6 +324,7 @@ class Filter(JailThread): logSys.debug("Ignore %s" % ip) continue logSys.debug("Found %s" % ip) + ## print "D: Adding a ticket for %s" % ((ip, unixTime, [line]),) self.failManager.addFailure(FailTicket(ip, unixTime, [line])) ## @@ -477,7 +480,7 @@ class FileFilter(Filter): return False # Try to open log file. try: - container.open() + has_content = container.open() # see http://python.org/dev/peps/pep-3151/ except IOError, e: logSys.error("Unable to open %s" % filename) @@ -492,7 +495,12 @@ class FileFilter(Filter): logSys.exception(e) return False - while True: + # 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 = container.readline() if (line == "") or not self._isActive(): # The jail reached the bottom or has been stopped @@ -555,10 +563,20 @@ class FileContainer: fd = self.__handler.fileno() flags = fcntl.fcntl(fd, fcntl.F_GETFD) fcntl.fcntl(fd, fcntl.F_SETFD, flags | fcntl.FD_CLOEXEC) + # Stat the file before even attempting to read it + stats = os.fstat(self.__handler.fileno()) + if not stats.st_size: + # yoh: so it is still an empty file -- nothing should be + # read from it yet + # print "D: no content -- return" + return False firstLine = self.__handler.readline() # Computes the MD5 of the first line. myHash = md5sum(firstLine).digest() - stats = os.fstat(self.__handler.fileno()) + ## print "D: fn=%s hashes=%s/%s inos=%s/%s pos=%s rotate=%s" % ( + ## self.__filename, self.__hash, myHash, stats.st_ino, self.__ino, self.__pos, + ## self.__hash != myHash or self.__ino != stats.st_ino) + ## sys.stdout.flush() # Compare hash and inode if self.__hash != myHash or self.__ino != stats.st_ino: logSys.debug("Log rotation detected for %s" % self.__filename) @@ -567,6 +585,7 @@ class FileContainer: self.__pos = 0 # Sets the file pointer to the last position. self.__handler.seek(self.__pos) + return True def readline(self): if self.__handler is None: @@ -580,6 +599,8 @@ class FileContainer: # Closes the file. self.__handler.close() self.__handler = None + ## print "D: Closed %s with pos %d" % (handler, self.__pos) + ## sys.stdout.flush() From 47ac39fb3451c1d29141aefb452124c05653ef87 Mon Sep 17 00:00:00 2001 From: Yaroslav Halchenko Date: Tue, 2 Jul 2013 23:37:41 -0400 Subject: [PATCH 09/13] TST: minor enhancement to test failure msg --- testcases/filtertestcase.py | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/testcases/filtertestcase.py b/testcases/filtertestcase.py index f2f6eb50..d918bbf7 100644 --- a/testcases/filtertestcase.py +++ b/testcases/filtertestcase.py @@ -447,7 +447,9 @@ def get_monitor_failures_testcase(Filter_): self.file = _copy_lines_between_files(GetFailures.FILENAME_01, self.name, n=14, mode='w') # Poll might need more time - self.assertTrue(self.isEmpty(4 + int(isinstance(self.filter, FilterPoll))*2)) + self.assertTrue(self.isEmpty(4 + int(isinstance(self.filter, FilterPoll))*2), + "Queue must be empty but it is not: %s." + % (', '.join([str(x) for x in self.jail.queue]))) self.assertRaises(FailManagerEmpty, self.filter.failManager.toBan) self.assertEqual(self.filter.failManager.getFailTotal(), 2) From 5d7ab9e7fb99287dae3d050ba04a7f5f046f4598 Mon Sep 17 00:00:00 2001 From: Yaroslav Halchenko Date: Tue, 2 Jul 2013 23:38:27 -0400 Subject: [PATCH 10/13] DOC: Changelog for preceding changes --- ChangeLog | 11 ++++++++++- 1 file changed, 10 insertions(+), 1 deletion(-) diff --git a/ChangeLog b/ChangeLog index 39c0a5aa..dc08641d 100644 --- a/ChangeLog +++ b/ChangeLog @@ -7,7 +7,7 @@ Fail2Ban (version 0.8.10) 2013/06/12 ================================================================================ -ver. 0.8.11 (2013/XX/XXX) - wanna-be-released +ver. 0.8.11 (2013/XX/XXX) - loves-unittests ----------- - Fixes: @@ -15,6 +15,15 @@ ver. 0.8.11 (2013/XX/XXX) - wanna-be-released * filter.d/common.conf -- make colon after [daemon] optional. Closes gh-267 * filter.d/apache-common.conf -- support apache 2.4 more detailed error log format. Closes gh-268 + * Backends changes detection and parsing. Close gh-223 and gh-103: + - Polling backend: detect changes in the files not only based on + mtime, but also on the size and inode. It should allow for + better detection of changes and log rotations on busy servers, + older python 2.4, and file systems with precision of mtime only + up to a second (e.g. ext3). + - All backends, possible race condition: do not read from a file + initially reported empty. Originally could have lead to + accounting for detected log lines multiple times. Daniel Black & Мернов Георгий * filter.d/dovecot.conf -- Fix when no TLS enabled - line doesn't end in , - New Features: From 5df6796e6943807e17b0e5ea962613af8f7b189f Mon Sep 17 00:00:00 2001 From: Yaroslav Halchenko Date: Tue, 2 Jul 2013 23:51:06 -0400 Subject: [PATCH 11/13] ENH: DNS resolution -- catch parent exception IMHO there is no good reason to capture only gaierror. on my network it was consistent to error out with ====================================================================== ERROR: testIgnoreIPNOK (testcases.filtertestcase.IgnoreIP) ---------------------------------------------------------------------- Traceback (most recent call last): File "/home/yoh/deb/gits/fail2ban/testcases/filtertestcase.py", line 166, in testIgnoreIPNOK self.assertFalse(self.filter.inIgnoreIPList(ip)) File "/home/yoh/deb/gits/fail2ban/server/filter.py", line 277, in inIgnoreIPList ips = DNSUtils.dnsToIp(i) File "/home/yoh/deb/gits/fail2ban/server/filter.py", line 625, in dnsToIp return socket.gethostbyname_ex(dns)[2] error: [Errno 11] Resource temporarily unavailable with this commit tests would pass normally as they should --- server/filter.py | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/server/filter.py b/server/filter.py index b7c2d091..6cd37ca1 100644 --- a/server/filter.py +++ b/server/filter.py @@ -623,9 +623,9 @@ class DNSUtils: """ try: return socket.gethostbyname_ex(dns)[2] - except socket.gaierror: - logSys.warn("Unable to find a corresponding IP address for %s" - % dns) + except socket.error, e: + logSys.warn("Unable to find a corresponding IP address for %s: %s" + % (dns, e)) return list() dnsToIp = staticmethod(dnsToIp) From 404574499d9d76c04e07c36b09a1fbcfb1361795 Mon Sep 17 00:00:00 2001 From: Yaroslav Halchenko Date: Tue, 2 Jul 2013 23:52:37 -0400 Subject: [PATCH 12/13] BF: fail2ban-testcases -- use full "warning" instead of warn for the verbosity dictionary --- fail2ban-testcases | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/fail2ban-testcases b/fail2ban-testcases index fc5cc146..89fc7deb 100755 --- a/fail2ban-testcases +++ b/fail2ban-testcases @@ -79,7 +79,7 @@ logSys = logging.getLogger("fail2ban") verbosity = {'heavydebug': 4, 'debug': 3, 'info': 2, - 'warn': 1, + 'warning': 1, 'error': 1, 'fatal': 0, None: 1}[opts.log_level] From e282d6b1c7aa15281be3fb748c11ad70ca5dd035 Mon Sep 17 00:00:00 2001 From: Yaroslav Halchenko Date: Wed, 3 Jul 2013 00:09:39 -0400 Subject: [PATCH 13/13] ENH: Remove unused any longer _ctime helper --- server/filterpoll.py | 5 ----- 1 file changed, 5 deletions(-) diff --git a/server/filterpoll.py b/server/filterpoll.py index 4cd7cb48..8b4038b8 100644 --- a/server/filterpoll.py +++ b/server/filterpoll.py @@ -30,11 +30,6 @@ from mytime import MyTime import time, logging, os -def _ctime(t): - """Given time in seconds provide string representation with milliseconds - """ - return "%s%.3f" %(time.strftime("%X", time.localtime(t)), (t-int(t))) - # Gets the instance of the logger. logSys = logging.getLogger("fail2ban.filter")