better reorder templates handling, code coverage increase (a small part of _reorderTemplate was not covered at all)

fail2ban/server/datedetector.py

@@ -92,7 +92,7 @@ class DateDetectorCache(object):
 		if self.__templates:
 			return self.__templates
 		with self.__lock:
-			if self.__templates:
+			if self.__templates: # pragma: no cover - race-condition + multi-threaded environment only
 				return self.__templates
 			self._addDefaultTemplate()
 			return self.__templates
@@ -324,7 +324,7 @@ class DateDetector(object):
 			ddtempl = self.__templates[i]
 			template = ddtempl.template
 			if template.flags & (DateTemplate.LINE_BEGIN|DateTemplate.LINE_END):
-				if logSys.getEffectiveLevel() <= logLevel-1:
+				if logSys.getEffectiveLevel() <= logLevel-1: # pragma: no cover - very-heavy debug
 					logSys.log(logLevel-1, "  try to match last anchored template #%02i ...", i)
 					match = template.matchDate(line)
 					ignoreBySearch = i
@@ -452,7 +452,7 @@ class DateDetector(object):
 			try:
 				date = template.getDate(line, timeMatch[0])
 				if date is not None:
-					if logSys.getEffectiveLevel() <= logLevel:
+					if logSys.getEffectiveLevel() <= logLevel: # pragma: no cover - heavy debug
 						logSys.log(logLevel, "  got time %f for %r using template %s",
 							date[0], date[1].group(1), template.name)
 					return date
@@ -478,29 +478,31 @@ class DateDetector(object):
 			weight = ddtempl.weight
 			## try to move faster (first if unused available, or half of part to current template position):
 			pos = self.__firstUnused if self.__firstUnused < num else num // 2
-			pweight = templates[pos].weight
 			## don't move too often (multiline logs resp. log's with different date patterns),
 			## if template not used too long, replace it also :
-			if logSys.getEffectiveLevel() <= logLevel:
-				logSys.log(logLevel, "  -> compare template #%02i & #%02i, weight %.3f > %.3f, hits %r > %r",
-					num, pos, weight, pweight, ddtempl.hits, templates[pos].hits)
-			if not pweight or weight > pweight or templates[pos].lastUsed < untime:
-				## if not larger (and target position recently used) - move slow (exact 1 position):
-				if weight <= pweight and templates[pos].lastUsed > untime:
-					pos = num-1
-					## if still smaller and template at position used, don't move:
-					pweight = templates[pos].weight
-					if logSys.getEffectiveLevel() <= logLevel:
-						logSys.log(logLevel, "  -> compare template #%02i & #%02i, weight %.3f > %.3f, hits %r > %r",
-							num, pos, weight, pweight, ddtempl.hits, templates[pos].hits)
-					if weight < pweight and templates[pos].lastUsed > untime:
-						return
-				del templates[num]
-				templates[pos:0] = [ddtempl]
-				## correct first unused:
-				while self.__firstUnused < len(templates) and templates[self.__firstUnused].hits:
-					self.__firstUnused += 1
+			def _moveable():
+				pweight = templates[pos].weight
 				if logSys.getEffectiveLevel() <= logLevel:
-					logSys.log(logLevel, "  -> moved template #%02i -> #%02i", num, pos)
-				return pos
+					logSys.log(logLevel, "  -> compare template #%02i & #%02i, weight %.3f > %.3f, hits %r > %r",
+						num, pos, weight, pweight, ddtempl.hits, templates[pos].hits)
+				return weight > pweight or untime > templates[pos].lastUsed
+			##
+			## if not moveable (smaller weight or target position recently used):
+			if not _moveable():
+				## try to move slow (exact 1 position):
+				if pos == num-1:
+					return num				
+				pos = num-1
+				## if still smaller and template at position used, don't move:
+				if not _moveable():
+					return num				
+			## move:
+			del templates[num]
+			templates[pos:0] = [ddtempl]
+			## correct first unused:
+			while self.__firstUnused < len(templates) and templates[self.__firstUnused].hits:
+				self.__firstUnused += 1
+			if logSys.getEffectiveLevel() <= logLevel:
+				logSys.log(logLevel, "  -> moved template #%02i -> #%02i", num, pos)
+			return pos
 		return num

fail2ban/tests/datedetectortestcase.py

@@ -250,12 +250,12 @@ class DateDetectorTest(LogCaptureTestCase):
 			("030324  0:04:00",            "server mysqld[1000]: 030324  0:04:00 [Warning] Access denied ..."
 																				" foreign-input just some free text 2003-03-07 17:05:01 test", 10),
 			# distance collision detection (first date should be found):
-			("Sep 16 21:30:26",            "server mysqld[1020]: Sep 16 21:30:26 server mysqld: 030916 21:30:26 [Warning] Access denied", 10),
+			("Sep 16 21:30:26",            "server mysqld[1020]: Sep 16 21:30:26 server mysqld: 030916 21:30:26 [Warning] Access denied", 15),
 			# just to test sorting:
 			("2005-10-07 06:09:42",        "server mysqld[5906]: 2005-10-07 06:09:42 5907 [Warning] Access denied", 20),
 			("2005-10-08T15:26:18.237955", "server mysqld[5906]: 2005-10-08T15:26:18.237955 6 [Note] Access denied", 20),
 			# date format changed again:
-			("051009 10:05:30",            "server mysqld[1000]: 051009 10:05:30 [Warning] Access denied ...", 20),
+			("051009 10:05:30",            "server mysqld[1000]: 051009 10:05:30 [Warning] Access denied ...", 50),
 		):
 			logSys.debug('== test: %r', (debit, line, cnt))
 			for i in range(cnt):