[temp commit] 2nd try to optimize datedetector/datetemplate functionality (almost ready, needs fine tuning)

fail2ban/client/fail2banregex.py

@@ -122,15 +122,15 @@ Report bugs to https://github.com/fail2ban/fail2ban/issues
 	p.add_options([
 		Option("-d", "--datepattern",
 			   help="set custom pattern used to match date/times"),
-		Option("-e", "--encoding",
+		Option("-e", "--encoding", default=PREFER_ENC,
 			   help="File encoding. Default: system locale"),
-		Option("-r", "--raw", action='store_true',
+		Option("-r", "--raw", action='store_true', default=False,
 			   help="Raw hosts, don't resolve dns"),
 		Option("--usedns", action='store', default=None,
 			   help="DNS specified replacement of tags <HOST> 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"),
+			   help="maxlines for multi-line regex."),
 		Option("-m", "--journalmatch",
 			   help="journalctl style matches overriding filter file. "
 			   "\"systemd-journal\" only"),
@@ -143,6 +143,8 @@ Report bugs to https://github.com/fail2ban/fail2ban/issues
 			   help="Increase verbosity"),
 		Option("--verbosity", action="store", dest="verbose", type=int,
 			   help="Set numerical level of verbosity (0..4)"),
+		Option("--verbose-date", "--VD", action='store_true',
+			   help="Verbose date patterns/regex in output"),
 		Option("-D", "--debuggex", action='store_true',
 			   help="Produce debuggex.com urls for debugging there"),
 		Option("--print-no-missed", action='store_true',
@@ -215,14 +217,8 @@ class LineStats(object):
 class Fail2banRegex(object):
 
 	def __init__(self, opts):
-		self._verbose = opts.verbose
+		# set local protected memebers from given options:
-		self._debuggex = opts.debuggex
+		self.__dict__.update(dict(('_'+o,v) for o,v in opts.__dict__.iteritems()))
-		self._maxlines = 20
-		self._print_no_missed = opts.print_no_missed
-		self._print_no_ignored = opts.print_no_ignored
-		self._print_all_matched = opts.print_all_matched
-		self._print_all_missed = opts.print_all_missed
-		self._print_all_ignored = opts.print_all_ignored
 		self._maxlines_set = False		  # so we allow to override maxlines in cmdline
 		self._datepattern_set = False
 		self._journalmatch = None
@@ -236,23 +232,20 @@ class Fail2banRegex(object):
 
 		if opts.maxlines:
 			self.setMaxLines(opts.maxlines)
+		else:
+			self._maxlines = 20
 		if opts.journalmatch is not None:
 			self.setJournalMatch(opts.journalmatch.split())
 		if opts.datepattern:
 			self.setDatePattern(opts.datepattern)
-		if opts.encoding:
-			self.encoding = opts.encoding
-		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('<LOG>', self.encoding, line)
+		return FileContainer.decode_line('<LOG>', self._encoding, line)
 
 	def encode_line(self, line):
-		return line.encode(self.encoding, 'ignore')
+		return line.encode(self._encoding, 'ignore')
 
 	def setDatePattern(self, pattern):
 		if not self._datepattern_set:
@@ -350,7 +343,7 @@ class Fail2banRegex(object):
 		orgLineBuffer = self._filter._Filter__lineBuffer
 		fullBuffer = len(orgLineBuffer) >= self._filter.getMaxLines()
 		try:
-			line, ret = self._filter.processLine(line, date, checkAllRegex=True, returnRawHost=self.raw)
+			line, ret = self._filter.processLine(line, date, checkAllRegex=True, returnRawHost=self._raw)
 			for match in ret:
 				# Append True/False flag depending if line was matched by
 				# more than one regex
@@ -479,8 +472,11 @@ class Fail2banRegex(object):
 			out = []
 			for template in self._filter.dateDetector.templates:
 				if self._verbose or template.hits:
-					out.append("[%d] %s" % (
+					out.append("[%d] %s" % (template.hits, template.name))
-						template.hits, template.name))
+					if self._verbose_date:
+						out.append("    # weight: %3s, pattern: %s" % (
+							template.weight, getattr(template, 'pattern', ''),))
+						out.append("    # regex:   %s" % (getattr(template, 'regex', ''),))
 			pprint_list(out, "[# of hits] date format")
 
 		output( "\nLines: %s" % self._line_stats, )
@@ -518,7 +514,7 @@ class Fail2banRegex(object):
 			try:
 				hdlr = open(cmd_log, 'rb')
 				output( "Use         log file : %s" % cmd_log )
-				output( "Use         encoding : %s" % self.encoding )
+				output( "Use         encoding : %s" % self._encoding )
 				test_lines = self.file_lines_gen(hdlr)
 			except IOError as e:
 				output( e )

fail2ban/server/datedetector.py

@@ -60,16 +60,15 @@ class DateDetectorCache(object):
 			# exact given template with word benin-end boundary:
 			template = DatePatternRegex(template)
 		# additional template, that prefers datetime at start of a line (safety+performance feature):
-		template2 = copy.copy(template)
+		if 0 and hasattr(template, 'regex'):
-		if hasattr(template, 'pattern'):
+			template2 = copy.copy(template)
-			regex = template.pattern
+			regex = getattr(template, 'pattern', template.regex)
-			wordEnd = True
+			template2.setRegex(regex, wordBegin='start', wordEnd=True)
-		else:
+			if template2.name != template.name:
-			regex = template.regex
+				# increase weight of such templates, because they should be always
-			wordEnd = False
+				# preferred in template sorting process (bubble up):
-		template2.setRegex(regex, wordBegin='start', wordEnd=wordEnd)
+				template2.weight = 100
-		if template2.name != template.name:
+				self.__templates.append(template2)
-			self.__templates.append(template2)
 		# add template:
 		self.__templates.append(template)
 
@@ -80,35 +79,35 @@ class DateDetectorCache(object):
 		# 2005-01-23T21:59:59.981746, 2005-01-23 21:59:59
 		# simple date: 2005/01/23 21:59:59 
 		# custom for syslog-ng 2006.12.21 06:43:20
-		self._cacheTemplate("%Y(?P<_sep>[-/.])%m(?P=_sep)%d[T ]%H:%M:%S(?:[.,]%f)?(?:\s*%z)?")
+		self._cacheTemplate("%ExY(?P<_sep>[-/.])%m(?P=_sep)%d[T ]%H:%M:%S(?:[.,]%f)?(?:\s*%z)?")
 		# 20050123T215959, 20050123 215959
-		self._cacheTemplate("%Y%Em%Ed[T ]%EH%EM%ES(?:[.,]%f)?(?:\s*%z)?")
+		self._cacheTemplate("%ExY%Exm%Exd[T ]%ExH%ExM%ExS(?:[.,]%f)?(?:\s*%z)?")
 		# asctime with optional day, subsecond and/or year:
 		# Sun Jan 23 21:59:59.011 2005 
 		# prefixed with optional time zone (monit):
 		# PDT Apr 16 21:05:29
-		self._cacheTemplate("(?:%z )?(?:%a )?%b %d %H:%M:%S(?:\.%f)?(?: %Y)?")
+		self._cacheTemplate("(?:%z )?(?:%a )?%b %d %H:%M:%S(?:\.%f)?(?: %ExY)?")
 		# asctime with optional day, subsecond and/or year coming after day
 		# http://bugs.debian.org/798923
 		# Sun Jan 23 2005 21:59:59.011
-		self._cacheTemplate("(?:%a )?%b %d %Y %H:%M:%S(?:\.%f)?")
+		self._cacheTemplate("(?:%a )?%b %d %ExY %H:%M:%S(?:\.%f)?")
 		# simple date too (from x11vnc): 23/01/2005 21:59:59 
 		# and with optional year given by 2 digits: 23/01/05 21:59:59 
 		# (See http://bugs.debian.org/537610)
 		# 17-07-2008 17:23:25
-		self._cacheTemplate("%d(?P<_sep>[-/])%m(?P=_sep)(?:%Y|%y) %H:%M:%S")
+		self._cacheTemplate("%d(?P<_sep>[-/])%m(?P=_sep)(?:%ExY|%Exy) %H:%M:%S")
 		# Apache format optional time zone:
 		# [31/Oct/2006:09:22:55 -0000]
 		# 26-Jul-2007 15:20:52
 		# named 26-Jul-2007 15:20:52.252
 		# roundcube 26-Jul-2007 15:20:52 +0200
-		self._cacheTemplate("%d(?P<_sep>[-/])%b(?P=_sep)%Y[ :]?%H:%M:%S(?:\.%f)?(?: %z)?")
+		self._cacheTemplate("%d(?P<_sep>[-/])%b(?P=_sep)%ExY[ :]?%H:%M:%S(?:\.%f)?(?: %z)?")
 		# CPanel 05/20/2008:01:57:39
-		self._cacheTemplate("%m/%d/%Y:%H:%M:%S")
+		self._cacheTemplate("%m/%d/%ExY:%H:%M:%S")
 		# 01-27-2012 16:22:44.252
 		# subseconds explicit to avoid possible %m<->%d confusion
-		# with previous ("%d-%m-%Y %H:%M:%S" by "%d(?P<_sep>[-/])%m(?P=_sep)(?:%Y|%y) %H:%M:%S")
+		# with previous ("%d-%m-%ExY %H:%M:%S" by "%d(?P<_sep>[-/])%m(?P=_sep)(?:%ExY|%Exy) %H:%M:%S")
-		self._cacheTemplate("%m-%d-%Y %H:%M:%S(?:\.%f)?")
+		self._cacheTemplate("%m-%d-%ExY %H:%M:%S(?:\.%f)?")
 		# TAI64N
 		self._cacheTemplate(DateTai64n())
 		# Epoch
@@ -116,13 +115,13 @@ class DateDetectorCache(object):
 		# Only time information in the log
 		self._cacheTemplate("^%H:%M:%S")
 		# <09/16/08@05:03:30>
-		self._cacheTemplate("^<%m/%d/%y@%H:%M:%S>")
+		self._cacheTemplate("^<%m/%d/%Exy@%H:%M:%S>")
 		# MySQL: 130322 11:46:11
-		self._cacheTemplate("%y%Em%Ed  ?%H:%M:%S")
+		self._cacheTemplate("%Exy%Exm%Exd  ?%H:%M:%S")
 		# Apache Tomcat
-		self._cacheTemplate("%b %d, %Y %I:%M:%S %p")
+		self._cacheTemplate("%b %d, %ExY %I:%M:%S %p")
 		# ASSP: Apr-27-13 02:33:06
-		self._cacheTemplate("^%b-%d-%y %H:%M:%S")
+		self._cacheTemplate("^%b-%d-%Exy %H:%M:%S")
 
 
 class DateDetectorTemplate(object):
@@ -218,14 +217,14 @@ class DateDetector(object):
 		"""
 		i = 0
 		with self.__lock:
-			for ddtemplate in self.__templates:
+			for ddtempl in self.__templates:
-				template = ddtemplate.template
+				template = ddtempl.template
 				match = template.matchDate(line)
-				if not match is None:
+				if match is not None:
 					if logSys.getEffectiveLevel() <= logLevel:
 						logSys.log(logLevel, "Matched time template %s", template.name)
-					ddtemplate.hits += 1
+					ddtempl.hits += 1
-					ddtemplate.lastUsed = time.time()
+					ddtempl.lastUsed = time.time()
 					# if not first - try to reorder current template (bubble up), they will be not sorted anymore:
 					if i:
 						self._reorderTemplate(i)
@@ -254,32 +253,21 @@ class DateDetector(object):
 			The Unix timestamp returned from the first successfully matched
 			template or None if not found.
 		"""
-		if timeMatch:
+		# search match for all specified templates:
-			template = timeMatch[1]
+		if timeMatch is None:
-			if template is not None:
+			timeMatch = self.matchTime(line)
-				try:
+		# convert:
-					date = template.getDate(line, timeMatch[0])
+		template = timeMatch[1]
-					if date is not None:
+		if template is not None:
-						if logSys.getEffectiveLevel() <= logLevel:
+			try:
-							logSys.log(logLevel, "Got time %f for %r using template %s",
+				date = template.getDate(line, timeMatch[0])
-								date[0], date[1].group(), template.name)
+				if date is not None:
-						return date
-				except ValueError:
-					return None
-		with self.__lock:
-			for ddtemplate in self.__templates:
-				template = ddtemplate.template
-				try:
-					date = template.getDate(line)
-					if date is None:
-						continue
 					if logSys.getEffectiveLevel() <= logLevel:
 						logSys.log(logLevel, "Got time %f for %r using template %s",
 							date[0], date[1].group(), template.name)
 					return date
-				except ValueError: # pragma: no cover
+			except ValueError:
-					pass
+				return None
-			return None
 
 	def _reorderTemplate(self, num):
 		"""Reorder template (bubble up) in template list if hits grows enough.
@@ -291,16 +279,16 @@ class DateDetector(object):
 		"""
 		if num:
 			templates = self.__templates
-			template = templates[num]
+			ddtempl = templates[num]
 		  ## current hits and time the template was long unused:
-			untime = template.lastUsed - self.__unusedTime
+			untime = ddtempl.lastUsed - self.__unusedTime
-			hits = template.hits
+			hits = ddtempl.hits * ddtempl.template.weight
 			## try to move faster (first 2 if it still unused, or half of part to current template position):
-			phits = 0
 			for pos in (0, 1, num // 2):
 				phits = templates[pos].hits
-				if not phits:
+				if not phits: # if we've found an unused
 					break
+			phits *= templates[pos].template.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 not phits or hits > phits + 5 or templates[pos].lastUsed < untime:
@@ -308,8 +296,9 @@ class DateDetector(object):
 				if hits <= phits and templates[pos].lastUsed > untime:
 					pos = num-1
 					## if still smaller and template at position used, don't move:
-					if hits < templates[pos].hits and templates[pos].lastUsed > untime:
+					phits = templates[pos].hits * templates[pos].template.weight
+					if hits < phits and templates[pos].lastUsed > untime:
 						return
-				templates[pos], templates[num] = template, templates[pos]
+				templates[pos], templates[num] = ddtempl, templates[pos]
 
 

fail2ban/server/datetemplate.py

@@ -32,6 +32,9 @@ from ..helpers import getLogger
 
 logSys = getLogger(__name__)
 
+RE_NO_WRD_BOUND_BEG = re.compile(r'^(?:\^|\*\*|\(\?:\^)')
+RE_NO_WRD_BOUND_END = re.compile(r'(?<!\\)(?:\$|\*\*)$')
+RE_DEL_WRD_BOUNDS =   re.compile(r'^\*\*|(?<!\\)\*\*$')
 
 class DateTemplate(object):
 	"""A template which searches for and returns a date from a log line.
@@ -46,20 +49,11 @@ class DateTemplate(object):
 	"""
 
 	def __init__(self):
-		self._name = ""
+		self.name = ""
+		self.weight = 1
 		self._regex = ""
 		self._cRegex = None
 
-	@property
-	def name(self):
-		"""Name assigned to template.
-		"""
-		return self._name
-
-	@name.setter
-	def name(self, name):
-		self._name = name
-
 	def getRegex(self):
 		return self._regex
 
@@ -73,10 +67,12 @@ class DateTemplate(object):
 		wordBegin : bool
 			Defines whether the regex should be modified to search at beginning of a
 			word, by adding special boundary r'(?=^|\b|\W)' to start of regex.
+			Can be disabled with specifying of ** at front of regex.
 			Default True.
 		wordEnd : bool
 			Defines whether the regex should be modified to search at end of a word,
 			by adding special boundary r'(?=\b|\W|$)' to end of regex.
+			Can be disabled with specifying of ** at end of regex.
 			Default True.
 
 		Raises
@@ -85,12 +81,16 @@ class DateTemplate(object):
 			If regular expression fails to compile
 		"""
 		regex = regex.strip()
-		if wordBegin and not re.search(r'^\^', regex):
+		# if word or line start boundary:
-			regex = (r'(?<=^|\b)' if wordBegin != 'start' else r"^(?<=\W)?") + regex
+		if wordBegin and not RE_NO_WRD_BOUND_BEG.search(regex):
-			self._name = ('[*WD-BEG]' if wordBegin != 'start' else '[^LN-BEG]') + self._name
+			regex = (r'(?=^|\b|\W)' if wordBegin != 'start' else r"(?:^|(?<=^\W)|(?<=^\W{2}))") + regex
-		if wordEnd and not re.search(r'\$$', regex):
+			self.name = ('{*WD-BEG}' if wordBegin != 'start' else '{^LN-BEG}') + self.name
+		# if word end boundary:
+		if wordEnd and not RE_NO_WRD_BOUND_END.search(regex):
 			regex += r'(?=\b|\W|$)'
-			self._name += ('[*WD-END]' if wordEnd else '')
+			self.name += ('{*WD-END}' if wordEnd else '')
+		# remove possible special pattern "**" in front and end of regex:
+		regex = RE_DEL_WRD_BOUNDS.sub('', regex)
 		self._regex = regex
 
 	regex = property(getRegex, setRegex, doc=
@@ -181,15 +181,8 @@ class DatePatternRegex(DateTemplate):
 	pattern
 	"""
 	
-	_patternRE = re.compile(getTimePatternRE())
+	_patternRE, _patternName = getTimePatternRE()
-	_patternName = {
+	_patternRE = re.compile(_patternRE)
-		'a': "DAY", 'A': "DAYNAME", 'b': "MON", 'B': "MONTH", 'd': "Day",
-		'H': "24hour", 'I': "12hour", 'j': "Yearday", 'm': "Month",
-		'M': "Minute", 'p': "AMPM", 'S': "Second", 'U': "Yearweek",
-		'w': "Weekday", 'W': "Yearweek", 'y': 'Year2', 'Y': "Year", '%': "%",
-		'z': "Zone offset", 'f': "Microseconds", 'Z': "Zone name"}
-	for _key in set(timeRE) - set(_patternName): # may not have them all...
-		_patternName[_key] = "%%%s" % _key
 
 	def __init__(self, pattern=None, **kwargs):
 		super(DatePatternRegex, self).__init__()
@@ -216,7 +209,7 @@ class DatePatternRegex(DateTemplate):
 	def setRegex(self, pattern, wordBegin=True, wordEnd=True):
 		self._pattern = pattern
 		fmt = self._patternRE.sub(r'%(\1)s', pattern)
-		self._name = fmt % self._patternName
+		self.name = fmt % self._patternName
 		super(DatePatternRegex, self).setRegex(fmt % timeRE, wordBegin, wordEnd)
 
 	def getDate(self, line, dateMatch=None):

fail2ban/server/mytime.py

@@ -41,6 +41,21 @@ class MyTime:
 	"""
 
 	myTime = None
+	alternateNowTime = None
+	alternateNow = None
+
+	@staticmethod
+	def setAlternateNow(t):
+		"""Set current time.
+
+		Use None in order to always get the real current time.
+
+		@param t the time to set or None
+		"""
+
+		MyTime.alternateNowTime = t
+		MyTime.alternateNow = \
+			datetime.datetime.fromtimestamp(t) if t is not None else None
 
 	@staticmethod
 	def setTime(t):
@@ -84,8 +99,9 @@ class MyTime:
 		"""
 		if MyTime.myTime is None:
 			return datetime.datetime.now()
-		else:
+		if MyTime.myTime == MyTime.alternateNowTime:
-			return datetime.datetime.fromtimestamp(MyTime.myTime)
+			return MyTime.alternateNow
+		return datetime.datetime.fromtimestamp(MyTime.myTime)
 
 	@staticmethod
 	def localtime(x=None):

fail2ban/server/strptime.py

@@ -26,24 +26,59 @@ from .mytime import MyTime
 
 locale_time = LocaleTime()
 timeRE = TimeRE()
+
+def _getYearCentRE(cent=(0,3), distance=3, now=(MyTime.now(), MyTime.alternateNow)):
+	""" Build century regex for last year and the next years (distance).
+		
+	Thereby respect possible run in the test-cases (alternate date used there)
+	"""
+	cent = lambda year, f=cent[0], t=cent[1]: str(year)[f:t]
+	exprset = set( cent(now[0].year + i) for i in (-1, distance) )
+	if len(now) and now[1]:
+		exprset |= set( cent(now[1].year + i) for i in (-1, distance) )
+	return "(?:%s)" % "|".join(exprset) if len(exprset) > 1 else "".join(exprset)
+
 #todo: implement literal time zone support like CET, PST, PDT, etc (via pytz):
 #timeRE['z'] = r"%s?(?P<z>Z|[+-]\d{2}(?::?[0-5]\d)?|[A-Z]{3})?" % timeRE['Z']
 timeRE['z'] = r"(?P<z>Z|[+-]\d{2}(?::?[0-5]\d)?)"
 
-# Extend build-in TimeRE with some exact (two-digit) patterns:
+# Extend build-in TimeRE with some exact patterns
-timeRE['Ed'] = r"(?P<d>3[0-1]|[1-2]\d|0[1-9])"
+# exact two-digit patterns:
-timeRE['Em'] = r"(?P<m>1[0-2]|0[1-9])"
+timeRE['Exd'] = r"(?P<d>3[0-1]|[1-2]\d|0[1-9])"
-timeRE['EH'] = r"(?P<H>2[0-3]|[0-1]\d)"
+timeRE['Exm'] = r"(?P<m>1[0-2]|0[1-9])"
-timeRE['EM'] = r"(?P<M>[0-5]\d)"
+timeRE['ExH'] = r"(?P<H>2[0-3]|[0-1]\d)"
-timeRE['ES'] = r"(?P<S>6[0-1]|[0-5]\d)"
+timeRE['ExM'] = r"(?P<M>[0-5]\d)"
+timeRE['ExS'] = r"(?P<S>6[0-1]|[0-5]\d)"
+# more precise year patterns, within same century of last year and
+# the next 3 years (for possible long uptime of fail2ban); thereby
+# respect possible run in the test-cases (alternate date used there):
+timeRE['ExY'] = r"(?P<Y>%s\d)" % _getYearCentRE(cent=(0,3), distance=3)
+timeRE['Exy'] = r"(?P<y>%s\d)" % _getYearCentRE(cent=(2,3), distance=3)
+# Special pattern "start of the line", analogous to `wordBegin='start'` of default templates:
+timeRE['ExLB'] = r"(?:^|(?<=^\W)|(?<=^\W{2}))"
 
 def getTimePatternRE():
 	keys = timeRE.keys()
-	return (r"%%(%%|%s|[%s])" % (
+	patt = (r"%%(%%|%s|[%s])" % (
 		"|".join([k for k in keys if len(k) > 1]),
 		"".join([k for k in keys if len(k) == 1]),
 	))
-
+	names = {
+		'a': "DAY", 'A': "DAYNAME", 'b': "MON", 'B': "MONTH", 'd': "Day",
+		'H': "24hour", 'I': "12hour", 'j': "Yearday", 'm': "Month",
+		'M': "Minute", 'p': "AMPM", 'S': "Second", 'U': "Yearweek",
+		'w': "Weekday", 'W': "Yearweek", 'y': 'Year2', 'Y': "Year", '%': "%",
+		'z': "Zone offset", 'f': "Microseconds", 'Z': "Zone name",
+		'ExLB': '{^LN-BEG}',
+	}
+	for key in set(keys) - set(names): # may not have them all...
+		if key.startswith('Ex'):
+			kn = names.get(key[2:])
+			if kn:
+				names[key] = "Ex" + kn
+				continue
+		names[key] = "%%%s" % key
+	return (patt, names)
 
 def reGroupDictStrptime(found_dict):
 	"""Return time from dictionary of strptime fields

fail2ban/tests/datedetectortestcase.py

@@ -30,7 +30,7 @@ import datetime
 
 from ..server.datedetector import DateDetector
 from ..server import datedetector
-from ..server.datetemplate import DateTemplate
+from ..server.datetemplate import DatePatternRegex, DateTemplate
 from .utils import setUpMyTime, tearDownMyTime, LogCaptureTestCase
 from ..helpers import getLogger
 
@@ -89,6 +89,10 @@ class DateDetectorTest(LogCaptureTestCase):
 		"""
 		dateUnix = 1106513999.0
 
+		# anchored - matching expression (pattern) is anchored
+		# bound - pattern can be tested using word boundary (e.g. False if contains in front some optional part)
+		# sdate - date string used in test log-line
+		# rdate - if specified, the result match, which differs from sdate
 		for anchored, bound, sdate, rdate in (
 			(False, True,  "Jan 23 21:59:59", None),
 			(False, False, "Sun Jan 23 21:59:59 2005", None),
@@ -113,15 +117,15 @@ class DateDetectorTest(LogCaptureTestCase):
 			(False, True,  "2005-01-23T20:59:59.252Z", None), #ISO 8601 (UTC)
 			(False, True,  "2005-01-23T15:59:59-05:00", None), #ISO 8601 with TZ
 			(False, True,  "2005-01-23 21:59:59", None), #ISO 8601 no TZ, assume local
-			(False, True,  "20050123T215959", None),   #Short ISO
+			(False, True,  "20050123T215959", None),   #Short ISO with T
-			(False, True,  "20050123 215959", None),   #Short ISO
+			(False, True,  "20050123 215959", None),   #Short ISO with space
 			(True,  True,  "<01/23/05@21:59:59>", None),
 			(False, True,  "050123 21:59:59", None), # MySQL
 			(True,  True,  "Jan-23-05 21:59:59", None), # ASSP like
 			(False, True,  "Jan 23, 2005 9:59:59 PM", None), # Apache Tomcat
 			(True,  True,  "1106513999", None), # Regular epoch
 			(True,  True,  "1106513999.000", None), # Regular epoch with millisec
-			(True,  True,  "[1106513999.000]", "1106513999.000"), # epoch squared
+			(True,  True,  "[1106513999.000]", "1106513999.000"), # epoch squared (brackets are not in match)
 			(False, True,  "audit(1106513999.000:987)", "1106513999.000"), # SELinux
 		):
 			logSys.debug('== test %r', (anchored, bound, sdate))
@@ -195,6 +199,141 @@ class DateDetectorTest(LogCaptureTestCase):
 			self.assertEqual(t.matchDate('aaaac').group(), 'aaaac')
 
 
+iso8601 = DatePatternRegex("%Y-%m-%d[T ]%H:%M:%S(?:\.%f)?%z")
+
+class CustomDateFormatsTest(unittest.TestCase):
+
+	def testIso8601(self):
+		date = datetime.datetime.utcfromtimestamp(
+			iso8601.getDate("2007-01-25T12:00:00Z")[0])
+		self.assertEqual(
+			date,
+			datetime.datetime(2007, 1, 25, 12, 0))
+		self.assertRaises(TypeError, iso8601.getDate, None)
+		self.assertRaises(TypeError, iso8601.getDate, date)
+
+		self.assertEqual(iso8601.getDate(""), None)
+		self.assertEqual(iso8601.getDate("Z"), None)
+
+		self.assertEqual(iso8601.getDate("2007-01-01T120:00:00Z"), None)
+		self.assertEqual(iso8601.getDate("2007-13-01T12:00:00Z"), None)
+		date = datetime.datetime.utcfromtimestamp(
+			iso8601.getDate("2007-01-25T12:00:00+0400")[0])
+		self.assertEqual(
+			date,
+			datetime.datetime(2007, 1, 25, 8, 0))
+		date = datetime.datetime.utcfromtimestamp(
+			iso8601.getDate("2007-01-25T12:00:00+04:00")[0])
+		self.assertEqual(
+			date,
+			datetime.datetime(2007, 1, 25, 8, 0))
+		date = datetime.datetime.utcfromtimestamp(
+			iso8601.getDate("2007-01-25T12:00:00-0400")[0])
+		self.assertEqual(
+			date,
+			datetime.datetime(2007, 1, 25, 16, 0))
+		date = datetime.datetime.utcfromtimestamp(
+			iso8601.getDate("2007-01-25T12:00:00-04")[0])
+		self.assertEqual(
+			date,
+			datetime.datetime(2007, 1, 25, 16, 0))
+
+	def testAmbiguousDatePattern(self):
+		defDD = DateDetector()
+		defDD.addDefaultTemplate()
+		for (matched, dp, line) in (
+			# positive case:
+			('Jan 23 21:59:59',   None, 'Test failure Jan 23 21:59:59 for 192.0.2.1'),
+			# ambiguous "unbound" patterns (missed):
+			(False,               None, 'Test failure TestJan 23 21:59:59.011 2015 for 192.0.2.1'),
+			(False,               None, 'Test failure Jan 23 21:59:59123456789 for 192.0.2.1'),
+			# ambiguous "no optional year" patterns (matched):
+			('Aug 8 11:25:50',      None, 'Aug 8 11:25:50 20030f2329b8 Authentication failed from 192.0.2.1'),
+			('Aug 8 11:25:50',      None, '[Aug 8 11:25:50] 20030f2329b8 Authentication failed from 192.0.2.1'),
+			('Aug 8 11:25:50 2014', None, 'Aug 8 11:25:50 2014 20030f2329b8 Authentication failed from 192.0.2.1'),
+			# direct specified patterns:
+			('20:00:00 01.02.2003',    r'%H:%M:%S %d.%m.%Y$', '192.0.2.1 at 20:00:00 01.02.2003'),
+			('[20:00:00 01.02.2003]',  r'\[%H:%M:%S %d.%m.%Y\]', '192.0.2.1[20:00:00 01.02.2003]'),
+			('[20:00:00 01.02.2003]',  r'\[%H:%M:%S %d.%m.%Y\]', '[20:00:00 01.02.2003]192.0.2.1'),
+			('[20:00:00 01.02.2003]',  r'\[%H:%M:%S %d.%m.%Y\]$', '192.0.2.1[20:00:00 01.02.2003]'),
+			('[20:00:00 01.02.2003]',  r'^\[%H:%M:%S %d.%m.%Y\]', '[20:00:00 01.02.2003]192.0.2.1'),
+			('[17/Jun/2011 17:00:45]', r'^\[%d/%b/%Y %H:%M:%S\]', '[17/Jun/2011 17:00:45] Attempt, IP address 192.0.2.1'),
+			('[17/Jun/2011 17:00:45]', r'\[%d/%b/%Y %H:%M:%S\]', 'Attempt [17/Jun/2011 17:00:45] IP address 192.0.2.1'),
+			('[17/Jun/2011 17:00:45]', r'\[%d/%b/%Y %H:%M:%S\]', 'Attempt IP address 192.0.2.1, date: [17/Jun/2011 17:00:45]'),
+			# direct specified patterns (begin/end, missed):
+			(False,                 r'%H:%M:%S %d.%m.%Y', '192.0.2.1x20:00:00 01.02.2003'),
+			(False,                 r'%H:%M:%S %d.%m.%Y', '20:00:00 01.02.2003x192.0.2.1'),
+			# direct specified unbound patterns (no begin/end boundary):
+			('20:00:00 01.02.2003', r'**%H:%M:%S %d.%m.%Y**', '192.0.2.1x20:00:00 01.02.2003'),
+			('20:00:00 01.02.2003', r'**%H:%M:%S %d.%m.%Y**', '20:00:00 01.02.2003x192.0.2.1'),
+			# pattern enclosed with stars (in comparison to example above):
+			('*20:00:00 01.02.2003*', r'\**%H:%M:%S %d.%m.%Y\**', 'test*20:00:00 01.02.2003*test'),
+			# direct specified patterns (begin/end, matched):
+			('20:00:00 01.02.2003', r'%H:%M:%S %d.%m.%Y', '192.0.2.1 20:00:00 01.02.2003'),
+			('20:00:00 01.02.2003', r'%H:%M:%S %d.%m.%Y', '20:00:00 01.02.2003 192.0.2.1'),
+			# wrong year in 1st date, so failed by convert using not precise year (filter used last known date),
+			# in the 2nd and 3th tests (with precise year) it should find correct the 2nd date:
+			(None,                  r'%Y-%Exm-%Exd %ExH:%ExM:%ExS',   "0000-12-30 00:00:00 - 2003-12-30 00:00:00"),
+			('2003-12-30 00:00:00', r'%ExY-%Exm-%Exd %ExH:%ExM:%ExS', "0000-12-30 00:00:00 - 2003-12-30 00:00:00"),
+			('2003-12-30 00:00:00', None,                             "0000-12-30 00:00:00 - 2003-12-30 00:00:00"),
+			# wrong date recognized short month/day (unbounded date pattern without separator between parts),
+			# in the 2nd and 3th tests (with precise month and day) it should find correct the 2nd date:
+			('200333 010203',   r'%Y%m%d %H%M%S',             "text:200333 010203 | date:20031230 010203"),
+			('20031230 010203', r'%ExY%Exm%Exd %ExH%ExM%ExS', "text:200333 010203 | date:20031230 010203"),
+			('20031230 010203', None,                         "text:200333 010203 | date:20031230 010203"),
+			# Explicit bound in start of the line using %ExLB key,
+			# (negative) in the 1st case without line begin boundary - wrong date may be found,
+			# (positive) in the 2nd case with line begin boundary - unexpected date / log line (not found)
+			# (positive) and in 3th case with line begin boundary - find the correct date
+			("20030101 000000", "%ExY%Exm%Exd %ExH%ExM%ExS",      "00001230 010203 - 20030101 000000"),
+			(None,              "%ExLB%ExY%Exm%Exd %ExH%ExM%ExS", "00001230 010203 - 20030101 000000"),
+			("20031230 010203", "%ExLB%ExY%Exm%Exd %ExH%ExM%ExS", "20031230 010203 - 20030101 000000"),
+			# Explicit bound in start of the line using %ExLB key, 
+			# up to 2 non-alphanumeric chars front, ** - no word boundary on the right
+			("20031230010203",  "%ExLB%ExY%Exm%Exd%ExH%ExM%ExS**", "2003123001020320030101000000"),
+			("20031230010203",  "%ExLB%ExY%Exm%Exd%ExH%ExM%ExS**", "#2003123001020320030101000000"),
+			("20031230010203",  "%ExLB%ExY%Exm%Exd%ExH%ExM%ExS**", "##2003123001020320030101000000"),
+			("20031230010203",  "%ExLB%ExY%Exm%Exd%ExH%ExM%ExS",   "[20031230010203]20030101000000"),
+		):
+			logSys.debug('== test: %r', (matched, dp, line))
+			if dp is None:
+				dd = defDD
+			else:
+				dp = DatePatternRegex(dp)
+				dd = DateDetector()
+				dd.appendTemplate(dp)
+			date = dd.getTime(line)
+			if matched:
+				self.assertTrue(date)
+				self.assertEqual(matched, date[1].group())
+			else:
+				self.assertEqual(date, None)
+
+	# def testAmbiguousUsingOrderedTemplates(self):
+	# 	defDD = DateDetector()
+	# 	defDD.addDefaultTemplate()
+	# 	for (matched, dp, line) in (
+	# 		# wrong date recognized short month/day (unbounded date pattern without separator),
+	# 		# in the 2nd and 3th tests (with precise month and day) it should find correct the 2nd date:
+	# 		('200333 010203',   r'%Y%m%d %H%M%S',             "text:200333 010203 | date:20031230 010203"),
+	# 		('20031230 010203', r'%ExY%Exm%Exd %ExH%ExM%ExS', "text:200333 010203 | date:20031230 010203"),
+	# 		('20031230 010203', None,                         "text:200333 010203 | date:20031230 010203"),
+	# 	):
+	# 		logSys.debug('== test: %r', (matched, dp, line))
+	# 		if dp is None:
+	# 			dd = defDD
+	# 		else:
+	# 			dp = DatePatternRegex(dp)
+	# 			dd = DateDetector()
+	# 			dd.appendTemplate(dp)
+	# 		date = dd.getTime(line)
+	# 		if matched:
+	# 			self.assertTrue(date)
+	# 			self.assertEqual(matched, date[1].group())
+	# 		else:
+	# 			self.assertEqual(date, None)
+
+
 #	def testDefaultTempate(self):
 #		self.__datedetector.setDefaultRegex("^\S{3}\s{1,2}\d{1,2} \d{2}:\d{2}:\d{2}")
 #		self.__datedetector.setDefaultPattern("%b %d %H:%M:%S")

fail2ban/tests/fail2banregextestcase.py

@@ -178,7 +178,7 @@ class Fail2banRegexTest(LogCaptureTestCase):
 
 	def testVerbose(self):
 		(opts, args, fail2banRegex) = _Fail2banRegex(
-			"--verbose", "--print-no-missed",
+			"--verbose", "--verbose-date", "--print-no-missed",
 			Fail2banRegexTest.FILENAME_02, 
 			Fail2banRegexTest.RE_00
 		)

fail2ban/tests/files/logs/zzz-generic-example

@@ -30,8 +30,8 @@ Jun 21 16:55:02   <auth.info> machine kernel: [  970.699396] @vserver_demo test-
 # failJSON: { "time": "2005-06-21T16:55:03", "match": true , "host": "192.0.2.3" }
 [Jun 21 16:55:03] <auth.info> machine kernel: [  970.699396] @vserver_demo test-demo(pam_unix)[13709] [ID 255 test] F2B: failure from 192.0.2.3
 
-# -- wrong time direct in journal-line (used last known date):
+# -- wrong time direct in journal-line (using precise year pattern):
-# failJSON: { "time": "2005-06-21T16:55:03", "match": true , "host": "192.0.2.1" }
+# failJSON: { "match": false}
 0000-12-30 00:00:00 server test-demo[47831]:  F2B: failure from 192.0.2.1
 # -- wrong time after newline in message (plist without escaped newlines):
 # failJSON: { "match": false }
@@ -42,8 +42,8 @@ Jun 22 20:37:04 server test-demo[402]: writeToStorage plist={
              applicationDate = "0000-12-30 00:00:00 +0000";
 # failJSON: { "match": false }
 }
-# -- wrong time direct in journal-line (used last known date):
+# -- wrong time direct in journal-line (using precise year pattern):
-# failJSON: { "time": "2005-06-22T20:37:04", "match": true , "host": "192.0.2.2" }
+# failJSON: { "match": false}
 0000-12-30 00:00:00 server test-demo[47831]:  F2B: failure from 192.0.2.2
 
 # failJSON: { "time": "2005-06-21T16:56:02", "match": true , "host": "192.0.2.250" }

fail2ban/tests/filtertestcase.py

@@ -283,10 +283,10 @@ class BasicFilter(unittest.TestCase):
 	def testGetSetDatePattern(self):
 		self.assertEqual(self.filter.getDatePattern(),
 			(None, "Default Detectors"))
-		self.filter.setDatePattern("^%Y-%m-%d-%H%M%S.%f %z")
+		self.filter.setDatePattern("^%Y-%m-%d-%H%M%S.%f %z **")
 		self.assertEqual(self.filter.getDatePattern(),
-			("^%Y-%m-%d-%H%M%S.%f %z",
+			("^%Y-%m-%d-%H%M%S.%f %z **",
-			"^Year-Month-Day-24hourMinuteSecond.Microseconds Zone offset"))
+			"^Year-Month-Day-24hourMinuteSecond.Microseconds Zone offset **"))
 
 	def testAssertWrongTime(self):
 		self.assertRaises(AssertionError, 

fail2ban/tests/misctestcase.py

@@ -23,13 +23,11 @@ __license__ = "GPL"
 
 import logging
 import os
-import re
 import sys
 import unittest
 import tempfile
 import shutil
 import fnmatch
-import datetime
 from glob import glob
 from StringIO import StringIO
 
@@ -37,8 +35,6 @@ from utils import LogCaptureTestCase, logSys as DefLogSys
 
 from ..helpers import formatExceptionInfo, mbasename, TraceBack, FormatterWithTraceBack, getLogger, uni_decode
 from ..helpers import splitwords
-from ..server.datedetector import DateDetector
-from ..server.datetemplate import DatePatternRegex
 from ..server.mytime import MyTime
 
 
@@ -320,91 +316,6 @@ class TestsUtilsTest(LogCaptureTestCase):
 			self.assertRaisesRegexp(Exception, 'not all arguments converted', lambda: logSys.debug('test', 1, 2, 3))
 
 
-iso8601 = DatePatternRegex("%Y-%m-%d[T ]%H:%M:%S(?:\.%f)?%z")
-
-
-class CustomDateFormatsTest(unittest.TestCase):
-
-	def testIso8601(self):
-		date = datetime.datetime.utcfromtimestamp(
-			iso8601.getDate("2007-01-25T12:00:00Z")[0])
-		self.assertEqual(
-			date,
-			datetime.datetime(2007, 1, 25, 12, 0))
-		self.assertRaises(TypeError, iso8601.getDate, None)
-		self.assertRaises(TypeError, iso8601.getDate, date)
-
-		self.assertEqual(iso8601.getDate(""), None)
-		self.assertEqual(iso8601.getDate("Z"), None)
-
-		self.assertEqual(iso8601.getDate("2007-01-01T120:00:00Z"), None)
-		self.assertEqual(iso8601.getDate("2007-13-01T12:00:00Z"), None)
-		date = datetime.datetime.utcfromtimestamp(
-			iso8601.getDate("2007-01-25T12:00:00+0400")[0])
-		self.assertEqual(
-			date,
-			datetime.datetime(2007, 1, 25, 8, 0))
-		date = datetime.datetime.utcfromtimestamp(
-			iso8601.getDate("2007-01-25T12:00:00+04:00")[0])
-		self.assertEqual(
-			date,
-			datetime.datetime(2007, 1, 25, 8, 0))
-		date = datetime.datetime.utcfromtimestamp(
-			iso8601.getDate("2007-01-25T12:00:00-0400")[0])
-		self.assertEqual(
-			date,
-			datetime.datetime(2007, 1, 25, 16, 0))
-		date = datetime.datetime.utcfromtimestamp(
-			iso8601.getDate("2007-01-25T12:00:00-04")[0])
-		self.assertEqual(
-			date,
-			datetime.datetime(2007, 1, 25, 16, 0))
-
-	def testAmbiguousDatePattern(self):
-		defDD = DateDetector()
-		defDD.addDefaultTemplate()
-		logSys = DefLogSys
-		for (matched, dp, line) in (
-			# positive case:
-			('Jan 23 21:59:59',   None, 'Test failure Jan 23 21:59:59 for 192.0.2.1'),
-			# ambiguous "unbound" patterns (missed):
-			(False,               None, 'Test failure TestJan 23 21:59:59.011 2015 for 192.0.2.1'),
-			(False,               None, 'Test failure Jan 23 21:59:59123456789 for 192.0.2.1'),
-			# ambiguous "no optional year" patterns (matched):
-			('Aug 8 11:25:50',      None, 'Aug 8 11:25:50 14430f2329b8 Authentication failed from 192.0.2.1'),
-			('Aug 8 11:25:50',      None, '[Aug 8 11:25:50] 14430f2329b8 Authentication failed from 192.0.2.1'),
-			('Aug 8 11:25:50 2014', None, 'Aug 8 11:25:50 2014 14430f2329b8 Authentication failed from 192.0.2.1'),
-			# direct specified patterns:
-			('20:00:00 01.02.2003',    r'%H:%M:%S %d.%m.%Y$', '192.0.2.1 at 20:00:00 01.02.2003'),
-			('[20:00:00 01.02.2003]',  r'\[%H:%M:%S %d.%m.%Y\]', '192.0.2.1[20:00:00 01.02.2003]'),
-			('[20:00:00 01.02.2003]',  r'\[%H:%M:%S %d.%m.%Y\]', '[20:00:00 01.02.2003]192.0.2.1'),
-			('[20:00:00 01.02.2003]',  r'\[%H:%M:%S %d.%m.%Y\]$', '192.0.2.1[20:00:00 01.02.2003]'),
-			('[20:00:00 01.02.2003]',  r'^\[%H:%M:%S %d.%m.%Y\]', '[20:00:00 01.02.2003]192.0.2.1'),
-			('[17/Jun/2011 17:00:45]', r'^\[%d/%b/%Y %H:%M:%S\]', '[17/Jun/2011 17:00:45] Attempt, IP address 192.0.2.1'),
-			('[17/Jun/2011 17:00:45]', r'\[%d/%b/%Y %H:%M:%S\]', 'Attempt [17/Jun/2011 17:00:45] IP address 192.0.2.1'),
-			('[17/Jun/2011 17:00:45]', r'\[%d/%b/%Y %H:%M:%S\]', 'Attempt IP address 192.0.2.1, date: [17/Jun/2011 17:00:45]'),
-			# direct specified patterns (begin/end, missed):
-			(False,                 r'%H:%M:%S %d.%m.%Y', '192.0.2.1x20:00:00 01.02.2003'),
-			(False,                 r'%H:%M:%S %d.%m.%Y', '20:00:00 01.02.2003x192.0.2.1'),
-			# direct specified patterns (begin/end, matched):
-			('20:00:00 01.02.2003', r'%H:%M:%S %d.%m.%Y', '192.0.2.1 20:00:00 01.02.2003'),
-			('20:00:00 01.02.2003', r'%H:%M:%S %d.%m.%Y', '20:00:00 01.02.2003 192.0.2.1'),
-		):
-			logSys.debug('== test: %r', (matched, dp, line))
-			if dp is None:
-				dd = defDD
-			else:
-				dp = DatePatternRegex(dp)
-				dd = DateDetector()
-				dd.appendTemplate(dp)
-			date = dd.getTime(line)
-			if matched:
-				self.assertTrue(date)
-				self.assertEqual(matched, date[1].group())
-			else:
-				self.assertEqual(date, None)
-
-
 class MyTimeTest(unittest.TestCase):
 
 	def testStr2Seconds(self):

fail2ban/tests/servertestcase.py

@@ -298,7 +298,7 @@ class Transmitter(TransmitterBase):
 
 	def testDatePattern(self):
 		self.setGetTest("datepattern", "%%%Y%m%d%H%M%S",
-			("%%%Y%m%d%H%M%S", "%YearMonthDay24hourMinuteSecond"),
+			("%%%Y%m%d%H%M%S", "{*WD-BEG}%YearMonthDay24hourMinuteSecond{*WD-END}"),
 			jail=self.jailName)
 		self.setGetTest(
 			"datepattern", "Epoch", (None, "Epoch"), jail=self.jailName)

fail2ban/tests/utils.py

@@ -48,6 +48,8 @@ from ..version import version
 
 logSys = getLogger(__name__)
 
+TEST_NOW = 1124013600
+
 CONFIG_DIR = os.environ.get('FAIL2BAN_CONFIG_DIR', None)
 
 if not CONFIG_DIR:
@@ -257,6 +259,10 @@ def initTests(opts):
 		def F2B_SkipIfNoNetwork():
 			raise unittest.SkipTest('Skip test because of "--no-network"')
 		unittest.F2B.SkipIfNoNetwork = F2B_SkipIfNoNetwork
+
+	# set alternate now for time related test cases:
+	MyTime.setAlternateNow(TEST_NOW)
+
 	# precache all invalid ip's (TEST-NET-1, ..., TEST-NET-3 according to RFC 5737):
 	c = DNSUtils.CACHE_ipToName
 	for i in xrange(255):
@@ -289,7 +295,7 @@ def setUpMyTime():
 	# yoh: we need to adjust TZ to match the one used by Cyril so all the timestamps match
 	os.environ['TZ'] = 'Europe/Zurich'
 	time.tzset()
-	MyTime.setTime(1124013600)
+	MyTime.setTime(TEST_NOW)
 
 
 def tearDownMyTime():
@@ -384,7 +390,6 @@ def gatherTests(regexps=None, opts=None):
 	tests.addTest(unittest.makeSuite(misctestcase.HelpersTest))
 	tests.addTest(unittest.makeSuite(misctestcase.SetupTest))
 	tests.addTest(unittest.makeSuite(misctestcase.TestsUtilsTest))
-	tests.addTest(unittest.makeSuite(misctestcase.CustomDateFormatsTest))
 	tests.addTest(unittest.makeSuite(misctestcase.MyTimeTest))
 	# Database
 	tests.addTest(unittest.makeSuite(databasetestcase.DatabaseTest))
@@ -404,6 +409,7 @@ def gatherTests(regexps=None, opts=None):
 
 	# DateDetector
 	tests.addTest(unittest.makeSuite(datedetectortestcase.DateDetectorTest))
+	tests.addTest(unittest.makeSuite(datedetectortestcase.CustomDateFormatsTest))
 	# Filter Regex tests with sample logs
 	tests.addTest(unittest.makeSuite(samplestestcase.FilterSamplesRegex))