ENH: add timezone offest and subsecond support to Datedetector

ChangeLog

@@ -66,6 +66,7 @@ ver. 0.8.11 (2013/XX/XXX) - loves-unittests
      and extra failure examples in sample logs
 	 * filter.d/apache-auth - added expressions for mod_authz, mod_auth and
      mod_auth_digest failures.
+   * Support %z (Timezone offset) and %f (sub-seconds) support for datedetector
   Daniel Black & Georgiy Mernov & ftoppi & Мернов Георгий
    * filter.d/exim.conf -- regex hardening and extra failure examples in
      sample logs

config/filter.d/apache-common.conf

@@ -18,4 +18,4 @@ after = apache-common.local
 # 2.2: [Sat Jun 01 11:23:08 2013] [error] [client 1.2.3.4]
 # 2.4: [Thu Jun 27 11:55:44.569531 2013] [core:info] [pid 4101:tid 2992634688] [client 1.2.3.4:46652]
 # Reference: https://github.com/fail2ban/fail2ban/issues/268
-_apache_error_client = \[[^]]*\] \[(error|\S+:\S+)\]( \[pid \d+:\S+ \d+\])? \[client <HOST>(:\d{1,5})?\]
+_apache_error_client = \[\] \[(error|\S+:\S+)\]( \[pid \d+:\S+ \d+\])? \[client <HOST>(:\d{1,5})?\]

config/filter.d/named-refused.conf

@@ -22,10 +22,7 @@ __daemon_combs_re=(?:%(__pid_re)s?:\s+%(__daemon_re)s|%(__daemon_re)s%(__pid_re)
 __line_prefix=(?:\s\S+ %(__daemon_combs_re)s\s+)?
 
 
-# note - (\.\d+)? is a really ugly catch of the microseconds not captured in
+failregex = ^%(__line_prefix)s( error:)?\s*client <HOST>#\S+( \([\S.]+\))?: (view (internal|external): )?query(?: \(cache\))? '.*' denied\s*$
-# in the date detector
+            ^%(__line_prefix)s( error:)?\s*client <HOST>#\S+( \([\S.]+\))?: zone transfer '\S+/AXFR/\w+' denied\s*$
-#
-failregex = ^%(__line_prefix)s(\.\d+)?( error:)?\s*client <HOST>#\S+( \([\S.]+\))?: (view (internal|external): )?query(?: \(cache\))? '.*' denied\s*$
-            ^%(__line_prefix)s(\.\d+)?( error:)?\s*client <HOST>#\S+( \([\S.]+\))?: zone transfer '\S+/AXFR/\w+' denied\s*$
             ^%(__line_prefix)s(\.\d+)?( error:)?\s*client <HOST>#\S+( \([\S.]+\))?: bad zone transfer request: '\S+/IN': non-authoritative zone \(NOTAUTH\)\s*$
 

config/filter.d/roundcube-auth.conf

@@ -17,7 +17,7 @@ before = common.conf
 #          (?:::f{4,6}:)?(?P<host>[\w\-.^_]+)
 # Values:  TEXT
 #
-failregex = ^\s*(\[(\s[+-][0-9]{4})?\])?(%(__hostname)s roundcube: IMAP Error)?: (FAILED login|Login failed) for .*? from <HOST>(\. AUTHENTICATE .*)?\s*$
+failregex = ^\s*(\[\])?(%(__hostname)s roundcube: IMAP Error)?: (FAILED login|Login failed) for .*? from <HOST>(\. AUTHENTICATE .*)?\s*$
 
 # Option:  ignoreregex
 # Notes.:  regex to ignore. If this regex matches, the line is ignored.

server/datedetector.py

@@ -48,8 +48,8 @@ class DateDetector:
 		try:
 			# asctime with subsecond
 			template = DateStrptime()
-			template.setName("WEEKDAY MONTH Day Hour:Minute:Second[.subsecond] Year")
+			template.setName("WEEKDAY MONTH Day Hour:Minute:Second.Subsecond Year")
-			template.setRegex("\S{3} \S{3}\s{1,2}\d{1,2} \d{2}:\d{2}:\d{2}\.\d+ \d{4}")
+			template.setRegex("\S{3} \S{3}\s{1,2}\d{1,2} \d{2}:\d{2}:\d{2}\.(?P<_f>\d+) \d{4}")
 			template.setPattern("%a %b %d %H:%M:%S.%f %Y")
 			self._appendTemplate(template)
 			# asctime without no subsecond
@@ -64,7 +64,7 @@ class DateDetector:
 			template.setRegex("\S{3} \S{3}\s{1,2}\d{1,2} \d{2}:\d{2}:\d{2}")
 			template.setPattern("%a %b %d %H:%M:%S")
 			self._appendTemplate(template)
-			# standard - most loose from above 3 so by default follows after
+			# standard - most loose from above so by default follows after
 			template = DateStrptime()
 			template.setName("MONTH Day Hour:Minute:Second")
 			template.setRegex("\S{3}\s{1,2}\d{1,2} \d{2}:\d{2}:\d{2}")
@@ -89,11 +89,11 @@ class DateDetector:
 			template.setRegex("\d{2}/\d{2}/\d{2} \d{2}:\d{2}:\d{2}")
 			template.setPattern("%d/%m/%y %H:%M:%S")
 			self._appendTemplate(template)
-			# Apache format [31/Oct/2006:09:22:55 -0000]
+			# Apache format [31/Oct/2006:09:22:55 -0200]
 			template = DateStrptime()
-			template.setName("Day/MONTH/Year:Hour:Minute:Second")
+			template.setName("Day/MONTH/Year:Hour:Minute:Second ZoneOffset")
-			template.setRegex("\d{2}/\S{3}/\d{4}:\d{2}:\d{2}:\d{2}")
+			template.setRegex("\d{2}/\S{3}/\d{4}:\d{2}:\d{2}:\d{2} (?P<_z>[+-]\d{4})")
-			template.setPattern("%d/%b/%Y:%H:%M:%S")
+			template.setPattern("%d/%b/%Y:%H:%M:%S %z")
 			self._appendTemplate(template)
 			# CPanel 05/20/2008:01:57:39
 			template = DateStrptime()
@@ -115,9 +115,15 @@ class DateDetector:
 			self._appendTemplate(template)
 			# named 26-Jul-2007 15:20:52.252 
 			template = DateStrptime()
-			template.setName("Day-MONTH-Year Hour:Minute:Second[.Millisecond]")
+			template.setName("Day-MONTH-Year Hour:Minute:Second.Subsecond")
-			template.setRegex("\d{2}-\S{3}-\d{4} \d{2}:\d{2}:\d{2}")
+			template.setRegex("\d{2}-\S{3}-\d{4} \d{2}:\d{2}:\d{2}\.(?P<_f>\d+)")
-			template.setPattern("%d-%b-%Y %H:%M:%S")
+			template.setPattern("%d-%b-%Y %H:%M:%S.%f")
+			self._appendTemplate(template)
+			# roundcube 26-Jul-2007 15:20:52 +0200
+			template = DateStrptime()
+			template.setName("Day-MONTH-Year Hour:Minute:Second ZoneOffset")
+			template.setRegex("\d{2}-\S{3}-\d{4} \d{2}:\d{2}:\d{2} (?P<_z>[+-]\d{4})")
+			template.setPattern("%d-%b-%Y %H:%M:%S %z")
 			self._appendTemplate(template)
 			# 17-07-2008 17:23:25
 			template = DateStrptime()
@@ -127,9 +133,9 @@ class DateDetector:
 			self._appendTemplate(template)
 			# 01-27-2012 16:22:44.252
 			template = DateStrptime()
-			template.setName("Month-Day-Year Hour:Minute:Second[.Millisecond]")
+			template.setName("Month-Day-Year Hour:Minute:Second.Subsecond")
-			template.setRegex("\d{2}-\d{2}-\d{4} \d{2}:\d{2}:\d{2}")
+			template.setRegex("\d{2}-\d{2}-\d{4} \d{2}:\d{2}:\d{2}\.(?P<_f>\d+)")
-			template.setPattern("%m-%d-%Y %H:%M:%S")
+			template.setPattern("%m-%d-%Y %H:%M:%S.%f")
 			self._appendTemplate(template)
 			# TAI64N
 			template = DateTai64n()

server/datetemplate.py

@@ -114,9 +114,12 @@ class DateStrptime(DateTemplate):
 	def __init__(self):
 		DateTemplate.__init__(self)
 		self.__pattern = ""
+		self.__unsupportedStrptimeBits = False
 	
 	def setPattern(self, pattern):
-		self.__pattern = pattern.strip()
+		self.__unsupported_f = not DateStrptime._f and re.search('%f', pattern)
+		self.__unsupported_z = not DateStrptime._z and re.search('%z', pattern)
+		self.__pattern = pattern
 		
 	def getPattern(self):
 		return self.__pattern
@@ -135,13 +138,23 @@ class DateStrptime(DateTemplate):
 	def getDate(self, line):
 		date = None
 		dateMatch = self.matchDate(line)
+
 		if dateMatch:
+			datePattern = self.getPattern()
+			if self.__unsupported_f:
+				if dateMatch.group('_f'):
+					datePattern = re.sub(r'%f', dateMatch.group('_f'), datePattern)
+					logSys.debug(u"Replacing %%f with %r now %r" % (dateMatch.group('_f'), datePattern))
+			if self.__unsupported_z:
+				if dateMatch.group('_z'):
+					datePattern = re.sub(r'%z', dateMatch.group('_z'), datePattern)
+					logSys.debug(u"Replacing %%z with %r now %r" % (dateMatch.group('_z'), datePattern))
 			try:
 				# Try first with 'C' locale
-				date = list(time.strptime(dateMatch.group(), self.getPattern()))
+				date = list(time.strptime(dateMatch.group(), datePattern))
 			except ValueError:
 				# Try to convert date string to 'C' locale
-				conv = self.convertLocale(dateMatch.group())
+				conv = self.convertLocale(datePattern)
 				try:
 					date = list(time.strptime(conv, self.getPattern()))
 				except (ValueError, re.error), e:
@@ -179,8 +192,28 @@ class DateStrptime(DateTemplate):
 					# NOTE: Possibly makes week/year day incorrect
 					date[1] = MyTime.gmtime()[1]
 					date[2] = MyTime.gmtime()[2]
+			if self.__unsupported_z:
+				z = dateMatch.group('_z')
+				if z:
+					date_sec = time.mktime(date)
+					date_sec -= (int(z[1:3]) * 60 + int(z[3:])) * int(z[0] + '60')
+					date = list(time.localtime(date_sec))
+					#date[8] = 0 # dst
+					logSys.debug(u"After working with offset date now %r" % date)
+				
 		return date
 
+try:
+	time.strptime("26-Jul-2007 15:20:52.252","%d-%b-%Y %H:%M:%S.%f")
+	DateStrptime._f = True
+except ValueError:
+	DateTemplate._f = False
+
+try:
+	time.strptime("24/Mar/2013:08:58:32 -0500","%d/%b/%Y:%H:%M:%S %z")
+	DateStrptime._z = True
+except ValueError:
+	DateStrptime._z = False
 
 class DateTai64n(DateTemplate):
 	

testcases/datedetectortestcase.py

@@ -65,16 +65,18 @@ class DateDetectorTest(unittest.TestCase):
 
 		for sdate in (
 			"Jan 23 21:59:59",
+			"Sun Jan 23 21:59:59.011 2005",
 			"Sun Jan 23 21:59:59 2005",
 			"Sun Jan 23 21:59:59",
 			"2005/01/23 21:59:59",
 			"2005.01.23 21:59:59",
 			"23/01/2005 21:59:59",
 			"23/01/05 21:59:59",
-			"23/Jan/2005:21:59:59",
+			"23/Jan/2005:22:59:59 +0100",
 			"01/23/2005:21:59:59",
 			"2005-01-23 21:59:59",
-			"23-Jan-2005 21:59:59",
+			"23-Jan-2005 21:59:59.02",
+			"23-Jan-2005 22:59:59 +0100",
 			"23-01-2005 21:59:59",
 			"01-23-2005 21:59:59.252", # reported on f2b, causes Feb29 fix to break
 			"@4000000041f4104f00000000", # TAI64N
@@ -129,6 +131,23 @@ class DateDetectorTest(unittest.TestCase):
 			for template in self.__datedetector.getTemplates()
 			if hasattr(template, "getPattern")]
 
+		ZERO = datetime.timedelta(0)
+		HOUR = datetime.timedelta(hours=1)
+
+		# A UTC class. to make %z formats work
+
+		class UTC(datetime.tzinfo):
+		    """UTC"""
+
+		    def utcoffset(self, dt):
+		        return ZERO
+
+		    def tzname(self, dt):
+				return "UTC"
+
+		    def dst(self, dt):
+				return ZERO
+
 		year = 2008 # Leap year, 08 for %y can be confused with both %d and %m
 		def iterDates(year):
 			for month in xrange(1, 13):
@@ -137,7 +156,7 @@ class DateDetectorTest(unittest.TestCase):
 						for minute in xrange(0, 60, 15):
 							for second in xrange(0, 60, 15): # Far enough?
 								yield datetime.datetime(
-									year, month, day, hour, minute, second)
+									year, month, day, hour, minute, second, 300, UTC())
 
 		overlapedTemplates = set()
 		for date in iterDates(year):
@@ -156,12 +175,12 @@ class DateDetectorTest(unittest.TestCase):
 				matchedTemplates = [template
 					for template in self.__datedetector.getTemplates()
 					if template.getHits() > 0]
-				assert matchedTemplates != [] # Should match at least one
+				self.assertNotEqual(matchedTemplates, [], "Date %r should match at least one template" % pattern)
 				if len(matchedTemplates) > 1:
 					overlapedTemplates.add((pattern, tuple(sorted(template.getName()
 						for template in matchedTemplates))))
 		if overlapedTemplates:
-			print "WARNING: The following date templates overlap:"
+			print("WARNING: The following date templates overlap:")
 			pprint.pprint(overlapedTemplates)
 
 #	def testDefaultTempate(self):

testcases/files/logs/apache-badbots

@@ -1,2 +1,2 @@
-# failJSON: { "time": "2007-03-05T14:39:21", "match": true , "host": "1.2.3.4" }
+# failJSON: { "time": "2007-03-05T13:39:21", "match": true , "host": "1.2.3.4" }
 1.2.3.4 - - [05/Mar/2007:14:39:21 +0100] "POST /123.html/trackback/ HTTP/1.0" 301 459 "http://www.mydomain.tld/123.html/trackback" "TrackBack/1.02"

testcases/files/logs/php-url-fopen

@@ -1,2 +1,2 @@
-# failJSON: { "time": "2009-03-26T08:44:20", "match": true , "host": "66.185.212.172" }
+# failJSON: { "time": "2009-03-26T13:44:20", "match": true , "host": "66.185.212.172" }
 66.185.212.172 - - [26/Mar/2009:08:44:20 -0500] "GET /index.php?n=http://eatmyfood.hostinginfive.com/pizza.htm? HTTP/1.1" 200 114 "-" "Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; .NET CLR 1.1.4322; .NET CLR 2.0.50727)"

testcases/files/logs/roundcube-auth

@@ -1,4 +1,4 @@
-# failJSON: { "time": "2013-01-22T22:28:21", "match": true , "host": "192.0.43.10" }
+# failJSON: { "time": "2013-01-22T20:28:21", "match": true , "host": "192.0.43.10" }
 [22-Jan-2013 22:28:21 +0200]: FAILED login for user1 from 192.0.43.10
 # failJSON: { "time": "2005-05-26T07:12:40", "match": true , "host": "10.1.1.47" }
 May 26 07:12:40 hamster roundcube: IMAP Error: Login failed for sales@example.com from 10.1.1.47