diff --git a/fail2ban/server/action.py b/fail2ban/server/action.py index de0c8efc..85bdd166 100644 --- a/fail2ban/server/action.py +++ b/fail2ban/server/action.py @@ -592,10 +592,12 @@ class CommandAction(ActionBase): std_level = retcode == 0 and logging.DEBUG or logging.ERROR if std_level >= logSys.getEffectiveLevel(): - stdout.seek(0) - logSys.log(std_level, "%s -- stdout: %r" % (realCmd, stdout.read())) - stderr.seek(0) - logSys.log(std_level, "%s -- stderr: %r" % (realCmd, stderr.read())) + stdout.seek(0); msg = stdout.read() + if msg != '': + logSys.log(std_level, "%s -- stdout: %r", realCmd, msg) + stderr.seek(0); msg = stderr.read() + if msg != '': + logSys.log(std_level, "%s -- stderr: %r", realCmd, msg) stdout.close() stderr.close() diff --git a/fail2ban/server/datedetector.py b/fail2ban/server/datedetector.py index a4839f5c..dbfb9e5d 100644 --- a/fail2ban/server/datedetector.py +++ b/fail2ban/server/datedetector.py @@ -29,6 +29,8 @@ from ..helpers import getLogger # Gets the instance of the logger. logSys = getLogger(__name__) +logLevel = 6 + class DateDetector(object): """Manages one or more date templates to find a date within a log line. @@ -147,7 +149,7 @@ class DateDetector(object): Returns ------- - re.MatchObject + re.MatchObject, DateTemplate The regex match returned from the first successfully matched template. """ @@ -156,10 +158,11 @@ class DateDetector(object): for template in self.__templates: match = template.matchDate(line) if not match is None: - logSys.debug("Matched time template %s" % template.name) + if logSys.getEffectiveLevel() <= logLevel: + logSys.log(logLevel, "Matched time template %s", template.name) template.hits += 1 - return match - return None + return (match, template) + return (None, None) finally: self.__lock.release() @@ -178,7 +181,7 @@ class DateDetector(object): ------- float The Unix timestamp returned from the first successfully matched - template. + template or None if not found. """ self.__lock.acquire() try: @@ -187,8 +190,9 @@ class DateDetector(object): date = template.getDate(line) if date is None: continue - logSys.debug("Got time %f for \"%r\" using template %s" % - (date[0], date[1].group(), template.name)) + 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: pass @@ -196,6 +200,38 @@ class DateDetector(object): finally: self.__lock.release() + def getTime2(self, line, timeMatch = None): + """Attempts to return the date on a log line using given template. + + This uses the templates' `getDate` method in an attempt to find + a date. + Method 'getTime2' is a little bit faster as 'getTime' if template was specified (cause works without locking and without cycle) + + Parameters + ---------- + line : str + Line which is searched by the date templates. + timeMatch (timeMatch, template) : (Match, DateTemplate) + Time match and template previously returned from matchTime + + Returns + ------- + float + The Unix timestamp returned from the first successfully matched + template or None if not found. + """ + date = None + if timeMatch: + template = timeMatch[1] + if template is not None: + date = template.getDate(line, timeMatch[0]) + if date is not None: + if logSys.getEffectiveLevel() <= logLevel: + logSys.log(logLevel, "Got time(2) %f for \"%r\" using template %s", + date[0], date[1].group(), template.name) + return date + return self.getTime(line) + def sortTemplate(self): """Sort the date templates by number of hits @@ -206,9 +242,11 @@ class DateDetector(object): """ self.__lock.acquire() try: - logSys.debug("Sorting the template list") + if logSys.getEffectiveLevel() <= logLevel: + logSys.log(logLevel, "Sorting the template list") self.__templates.sort(key=lambda x: x.hits, reverse=True) t = self.__templates[0] - logSys.debug("Winning template: %s with %d hits" % (t.name, t.hits)) + if logSys.getEffectiveLevel() <= logLevel: + logSys.log(logLevel, "Winning template: %s with %d hits", t.name, t.hits) finally: self.__lock.release() diff --git a/fail2ban/server/datetemplate.py b/fail2ban/server/datetemplate.py index bcd17ec1..e1f6b3de 100644 --- a/fail2ban/server/datetemplate.py +++ b/fail2ban/server/datetemplate.py @@ -98,7 +98,7 @@ class DateTemplate(object): return dateMatch @abstractmethod - def getDate(self, line): + def getDate(self, line, dateMatch=None): """Abstract method, which should return the date for a log line This should return the date for a log line, typically taking the @@ -134,7 +134,7 @@ class DateEpoch(DateTemplate): DateTemplate.__init__(self) self.regex = "(?:^|(?P(?<=^\[))|(?P(?<=audit\()))\d{10}(?:\.\d{3,6})?(?(selinux)(?=:\d+\))(?(square)(?=\])))" - def getDate(self, line): + def getDate(self, line, dateMatch=None): """Method to return the date for a log line. Parameters @@ -148,7 +148,8 @@ class DateEpoch(DateTemplate): Tuple containing a Unix timestamp, and the string of the date which was matched and in turned used to calculated the timestamp. """ - dateMatch = self.matchDate(line) + if not dateMatch: + dateMatch = self.matchDate(line) if dateMatch: # extract part of format which represents seconds since epoch return (float(dateMatch.group()), dateMatch) @@ -212,7 +213,7 @@ class DatePatternRegex(DateTemplate): def name(self, value): raise NotImplementedError("Name derived from pattern") - def getDate(self, line): + def getDate(self, line, dateMatch=None): """Method to return the date for a log line. This uses a custom version of strptime, using the named groups @@ -229,7 +230,8 @@ class DatePatternRegex(DateTemplate): Tuple containing a Unix timestamp, and the string of the date which was matched and in turned used to calculated the timestamp. """ - dateMatch = self.matchDate(line) + if not dateMatch: + dateMatch = self.matchDate(line) if dateMatch: groupdict = dict( (key, value) @@ -253,7 +255,7 @@ class DateTai64n(DateTemplate): # yoh: we should not add an additional front anchor self.setRegex("@[0-9a-f]{24}", wordBegin=False) - def getDate(self, line): + def getDate(self, line, dateMatch=None): """Method to return the date for a log line. Parameters @@ -267,7 +269,8 @@ class DateTai64n(DateTemplate): Tuple containing a Unix timestamp, and the string of the date which was matched and in turned used to calculated the timestamp. """ - dateMatch = self.matchDate(line) + if not dateMatch: + dateMatch = self.matchDate(line) if dateMatch: # extract part of format which represents seconds since epoch value = dateMatch.group() diff --git a/fail2ban/server/filter.py b/fail2ban/server/filter.py index 2dfeb174..296ff101 100644 --- a/fail2ban/server/filter.py +++ b/fail2ban/server/filter.py @@ -406,14 +406,16 @@ class Filter(JailThread): l = line.rstrip('\r\n') logSys.log(7, "Working on line %r", line) - timeMatch = self.dateDetector.matchTime(l) + (timeMatch, template) = self.dateDetector.matchTime(l) if timeMatch: tupleLine = ( l[:timeMatch.start()], l[timeMatch.start():timeMatch.end()], - l[timeMatch.end():]) + l[timeMatch.end():], + (timeMatch, template) + ) else: - tupleLine = (l, "", "") + tupleLine = (l, "", "", None) return "".join(tupleLine[::2]), self.findFailure( tupleLine, date, returnRawHost, checkAllRegex) @@ -475,7 +477,7 @@ class Filter(JailThread): self.__lastDate = date elif timeText: - dateTimeMatch = self.dateDetector.getTime(timeText) + dateTimeMatch = self.dateDetector.getTime2(timeText, tupleLine[3]) if dateTimeMatch is None: logSys.error("findFailure failed to parse timeText: " + timeText) @@ -492,7 +494,7 @@ class Filter(JailThread): date = self.__lastDate self.__lineBuffer = ( - self.__lineBuffer + [tupleLine])[-self.__lineBufferSize:] + self.__lineBuffer + [tupleLine[:3]])[-self.__lineBufferSize:] logSys.log(5, "Looking for failregex match of %r" % self.__lineBuffer) # Iterates over all the regular expressions. @@ -731,9 +733,9 @@ class FileFilter(Filter): break llen += len(line) l = line.rstrip('\r\n') - timeMatch = self.dateDetector.matchTime(l) + (timeMatch, template) = self.dateDetector.matchTime(l) if timeMatch: - dateTimeMatch = self.dateDetector.getTime(l[timeMatch.start():timeMatch.end()]) + dateTimeMatch = self.dateDetector.getTime2(l[timeMatch.start():timeMatch.end()], (timeMatch, template)) if not dateTimeMatch and lncntr: lncntr -= 1 continue diff --git a/fail2ban/server/server.py b/fail2ban/server/server.py index 3e371945..9836b61d 100644 --- a/fail2ban/server/server.py +++ b/fail2ban/server/server.py @@ -81,7 +81,7 @@ class Server: self.flushLogs() def start(self, sock, pidfile, force = False): - logSys.info("Starting Fail2ban v" + version.version) + logSys.info("Starting Fail2ban v%s", version.version) # Install signal handlers signal.signal(signal.SIGTERM, self.__sigTERMhandler) @@ -443,6 +443,7 @@ class Server: logger.addHandler(hdlr) # Does not display this message at startup. if not self.__logTarget is None: + logSys.info("Start Fail2ban v%s", version.version) logSys.info( "Changed logging target to %s for Fail2ban v%s" % ((target diff --git a/fail2ban/tests/datedetectortestcase.py b/fail2ban/tests/datedetectortestcase.py index facfda6d..095b706a 100644 --- a/fail2ban/tests/datedetectortestcase.py +++ b/fail2ban/tests/datedetectortestcase.py @@ -106,6 +106,7 @@ class DateDetectorTest(unittest.TestCase): (not anchored, "bogus-prefix ")): log = prefix + sdate + "[sshd] error: PAM: Authentication failure" + # with getTime: logtime = self.__datedetector.getTime(log) if should_match: self.assertNotEqual(logtime, None, "getTime retrieved nothing: failure for %s, anchored: %r, log: %s" % ( sdate, anchored, log)) @@ -118,6 +119,20 @@ class DateDetectorTest(unittest.TestCase): self.assertEqual(logMatch.group(), sdate) else: self.assertEqual(logtime, None, "getTime should have not matched for %r Got: %s" % (sdate, logtime)) + # with matchTime and getTime2 (this combination used in filter) : + matchTime = self.__datedetector.matchTime(log) + logtime = self.__datedetector.getTime2(log, matchTime) + if should_match: + self.assertNotEqual(logtime, None, "getTime retrieved nothing: failure for %s, anchored: %r, log: %s" % ( sdate, anchored, log)) + ( logUnix, logMatch ) = logtime + self.assertEqual(logUnix, dateUnix, "getTime comparison failure for %s: \"%s\" is not \"%s\"" % (sdate, logUnix, dateUnix)) + if sdate.startswith('audit('): + # yes, special case, the group only matches the number + self.assertEqual(logMatch.group(), '1106513999.000') + else: + self.assertEqual(logMatch.group(), sdate) + else: + self.assertEqual(logtime, None, "getTime should have not matched for %r Got: %s" % (sdate, logtime)) def testStableSortTemplate(self): old_names = [x.name for x in self.__datedetector.templates]