filter stability fix: prevent race condition - no ban if filter (backend) is continuously busy if too many messages will be found in log, e. g. initial scan of large log-file or journal (gh-2660)

ChangeLog

@@ -32,6 +32,8 @@ ver. 0.10.6-dev (20??/??/??) - development edition
   IPv6-capable now.
 
 ### Fixes
+* [stability] prevent race condition - no ban if filter (backend) is continuously busy if
+  too many messages will be found in log, e. g. initial scan of large log-file or journal (gh-2660)
 * python 3.9 compatibility (and Travis CI support)
 * restoring a large number (500+ depending on files ulimit) of current bans when using PyPy fixed
 * manual ban is written to database, so can be restored by restart (gh-2647)

fail2ban/server/filter.py

@@ -111,6 +111,8 @@ class Filter(JailThread):
 		self.onIgnoreRegex = None
 		## if true ignores obsolete failures (failure time < now - findTime):
 		self.checkFindTime = True
+		## if true prevents against retarded banning in case of RC by too many failures (disabled only for test purposes):
+		self.banASAP = True
 		## Ticks counter
 		self.ticks = 0
 		## Thread name:
@@ -625,7 +627,11 @@ class Filter(JailThread):
 				logSys.info(
 					"[%s] Found %s - %s", self.jailName, ip, datetime.datetime.fromtimestamp(unixTime).strftime("%Y-%m-%d %H:%M:%S")
 				)
-				self.failManager.addFailure(tick)
+				attempts = self.failManager.addFailure(tick)
+				# avoid RC on busy filter (too many failures) - if attempts for IP/ID reached maxretry,
+				# we can speedup ban, so do it as soon as possible:
+				if self.banASAP and attempts >= self.failManager.getMaxRetry():
+					self.performBan(ip)
 			# reset (halve) error counter (successfully processed line):
 			if self._errors:
 				self._errors //= 2

fail2ban/server/filtergamin.py

@@ -79,7 +79,8 @@ class FilterGamin(FileFilter):
 		this is a common logic and must be shared/provided by FileFilter
 		"""
 		self.getFailures(path)
-		self.performBan()
+		if not self.banASAP: # pragma: no cover
+			self.performBan()
 		self.__modified = False
 
 	##

fail2ban/server/filterpoll.py

@@ -117,7 +117,8 @@ class FilterPoll(FileFilter):
 
 				self.ticks += 1
 				if self.__modified:
-					self.performBan()
+					if not self.banASAP: # pragma: no cover
+						self.performBan()
 					self.__modified = False
 			except Exception as e: # pragma: no cover
 				if not self.active: # if not active - error by stop...

fail2ban/server/filterpyinotify.py

@@ -140,7 +140,8 @@ class FilterPyinotify(FileFilter):
 		"""
 		if not self.idle:
 			self.getFailures(path)
-			self.performBan()
+			if not self.banASAP: # pragma: no cover
+				self.performBan()
 			self.__modified = False
 
 	def _addPending(self, path, reason, isDir=False):

fail2ban/server/filtersystemd.py

@@ -318,7 +318,8 @@ class FilterSystemd(JournalFilter): # pragma: systemd no cover
 					else:
 						break
 				if self.__modified:
-					self.performBan()
+					if not self.banASAP: # pragma: no cover
+						self.performBan()
 					self.__modified = 0
 					# update position in log (time and iso string):
 					if self.jail.database is not None:

fail2ban/tests/filtertestcase.py

@@ -399,6 +399,7 @@ class IgnoreIP(LogCaptureTestCase):
 			self.filter.addFailRegex('^<HOST>')
 			self.filter.setDatePattern(r'{^LN-BEG}%Y-%m-%d %H:%M:%S(?:\s*%Z)?\s')
 			self.filter.setFindTime(10); # max 10 seconds back
+			self.filter.setMaxRetry(5); # don't ban here
 			#
 			self.pruneLog('[phase 1] DST time jump')
 			# check local time jump (DST hole):
@@ -757,6 +758,7 @@ class LogFileMonitor(LogCaptureTestCase):
 		_, self.name = tempfile.mkstemp('fail2ban', 'monitorfailures')
 		self.file = open(self.name, 'a')
 		self.filter = FilterPoll(DummyJail())
+		self.filter.banASAP = False # avoid immediate ban in this tests
 		self.filter.addLogPath(self.name, autoSeek=False)
 		self.filter.active = True
 		self.filter.addFailRegex(r"(?:(?:Authentication failure|Failed [-/\w+]+) for(?: [iI](?:llegal|nvalid) user)?|[Ii](?:llegal|nvalid) user|ROOT LOGIN REFUSED) .*(?: from|FROM) <HOST>")
@@ -974,6 +976,7 @@ def get_monitor_failures_testcase(Filter_):
 			self.file = open(self.name, 'a')
 			self.jail = DummyJail()
 			self.filter = Filter_(self.jail)
+			self.filter.banASAP = False # avoid immediate ban in this tests
 			self.filter.addLogPath(self.name, autoSeek=False)
 			# speedup search using exact date pattern:
 			self.filter.setDatePattern(r'^(?:%a )?%b %d %H:%M:%S(?:\.%f)?(?: %ExY)?')
@@ -1272,6 +1275,7 @@ def get_monitor_failures_journal_testcase(Filter_): # pragma: systemd no cover
 		def _initFilter(self, **kwargs):
 			self._getRuntimeJournal() # check journal available
 			self.filter = Filter_(self.jail, **kwargs)
+			self.filter.banASAP = False # avoid immediate ban in this tests
 			self.filter.addJournalMatch([
 				"SYSLOG_IDENTIFIER=fail2ban-testcases",
 				"TEST_FIELD=1",
@@ -1525,6 +1529,7 @@ class GetFailures(LogCaptureTestCase):
 		setUpMyTime()
 		self.jail = DummyJail()
 		self.filter = FileFilter(self.jail)
+		self.filter.banASAP = False # avoid immediate ban in this tests
 		self.filter.active = True
 		# speedup search using exact date pattern:
 		self.filter.setDatePattern(r'^(?:%a )?%b %d %H:%M:%S(?:\.%f)?(?: %ExY)?')
@@ -1714,6 +1719,7 @@ class GetFailures(LogCaptureTestCase):
 			self.pruneLog("[test-phase useDns=%s]" % useDns)
 			jail = DummyJail()
 			filter_ = FileFilter(jail, useDns=useDns)
+			filter_.banASAP = False # avoid immediate ban in this tests
 			filter_.active = True
 			filter_.failManager.setMaxRetry(1)	# we might have just few failures