BF: figure out minimal sleep time needed for mtime changes to get detected. Close #223, and probably #103

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

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()