diff --git a/fail2ban/server/action.py b/fail2ban/server/action.py index da7517f6..66657ba8 100644 --- a/fail2ban/server/action.py +++ b/fail2ban/server/action.py @@ -570,10 +570,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 fe5282fd..ba623f4a 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. @@ -142,7 +144,7 @@ class DateDetector(object): Returns ------- - re.MatchObject + re.MatchObject, DateTemplate The regex match returned from the first successfully matched template. """ @@ -151,10 +153,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() @@ -173,7 +176,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: @@ -182,8 +185,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 @@ -191,6 +195,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 @@ -201,9 +237,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 a5179ed1..013a8105 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) @@ -211,7 +212,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 @@ -228,7 +229,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) @@ -251,7 +253,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 @@ -265,7 +267,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 65e78142..30c8c48d 100644 --- a/fail2ban/server/filter.py +++ b/fail2ban/server/filter.py @@ -394,14 +394,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) @@ -469,7 +471,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) @@ -486,7 +488,7 @@ class Filter(JailThread): date = self.__lastDate self.__lineBuffer = ( - self.__lineBuffer + [tupleLine])[-self.__lineBufferSize:] + self.__lineBuffer + [tupleLine[:3]])[-self.__lineBufferSize:] # Iterates over all the regular expressions. for failRegexIndex, failRegex in enumerate(self.__failRegex): @@ -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 54ee0ef2..125086a5 100644 --- a/fail2ban/server/server.py +++ b/fail2ban/server/server.py @@ -65,7 +65,7 @@ class Server: self.quit() 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) @@ -429,8 +429,8 @@ class Server: logger.addHandler(hdlr) # Does not display this message at startup. if not self.__logTarget is None: - logSys.info("Changed logging target to %s for Fail2ban v%s" % - (target, version.version)) + logSys.info("Start Fail2ban v%s", version.version) + logSys.info("Changed logging target to %s", target) # Sets the logging target. self.__logTarget = target return True diff --git a/fail2ban/tests/datedetectortestcase.py b/fail2ban/tests/datedetectortestcase.py index 726e73f8..6f1fe35a 100644 --- a/fail2ban/tests/datedetectortestcase.py +++ b/fail2ban/tests/datedetectortestcase.py @@ -103,6 +103,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)) @@ -115,6 +116,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]