github
/
fail2ban
mirror of https://github.com/fail2ban/fail2ban
1
0
Fork 0
Code Issues Releases Wiki Activity

simplifying logic and shortening messages (delta in minutes; removed clock synchronization, because it is rarely an issue on fail2ban side, e. g. for remote logs only, etc)

pull/3053/head
sebres 2021-09-19 21:58:42 +02:00
parent d7afcde2e1
commit ec043cd202
2 changed files with 38 additions and 56 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

41
fail2ban/server/filter.py
View File

@ -655,46 +655,35 @@ class Filter(JailThread):
tupleLine = ("", self.__lastTimeText, line)
date = self.__lastDate
if self.checkFindTime:
if self.checkFindTime and date is not None:
# if in operation (modifications have been really found):
if self.inOperation:
# if weird date - we'd simulate now for timeing issue (too large deviation from now):
delta = date - MyTime.time()
if (date is None or abs(delta) > 60):
latency = "This could indicate a latency problem."
synchronization = "This could be a clock synchronization" + \
" problem; are you sure that NTP is set up?"
timezone = "This looks like a timezone problem."
msg = ""
if -15*60 <= delta <= 0:
msg = latency
elif 0 < delta <= 15*60:
msg = synchronization
else:
msg = timezone
# log time zone issue as warning once per day:
delta = int(date - MyTime.time())
if abs(delta) > 60:
delta /= 60
# log timing issue as warning once per day:
self._logWarnOnce("_next_simByTimeWarn",
("Found a log entry with a timestamp %ss %s the current time. %s",
abs(delta),
"before" if delta <= 0 else "after",
msg),
("Please check this jail and associated logs as there" +
" is potentially a timezone or latency problem: %s",
("Detected a log entry %sm %s the current time in operation mode. "
"This looks like a %s problem. Treating such entries as if they just happened.",
abs(delta), "before" if delta < 0 else "after",
"latency" if -55 <= delta < 0 else "timezone"
),
("Please check a jail for a timing issue. Line with odd timestamp: %s",
line))
# simulate now as date:
date = MyTime.time()
self.__lastDate = date
else:
# in initialization (restore) phase, if too old - ignore:
if date is not None and date < MyTime.time() - self.getFindTime():
if date < MyTime.time() - self.getFindTime():
# log time zone issue as warning once per day:
self._logWarnOnce("_next_ignByTimeWarn",
("Ignoring all log entries older than %s; these are probably" +
("Ignoring all log entries older than %ss; these are probably" +
" messages generated while fail2ban was not running.",
self.getFindTime()),
("Please check this jail and associated logs as" +
" there is potentially a timezone or latency problem: %s",
line))
("Please check a jail for a timing issue. Line with odd timestamp: %s",
line))
# ignore - too old (obsolete) entry:
return []

53
fail2ban/tests/filtertestcase.py
View File

@ -444,11 +444,11 @@ class IgnoreIP(LogCaptureTestCase):
def testTimeJump_InOperation(self):
self._testTimeJump(inOperation=True)
def testWrongTimeZone(self):
def testWrongTimeOrTZ(self):
try:
self.filter.addFailRegex('fail from <ADDR>$')
self.filter.setDatePattern(r'{^LN-BEG}%Y-%m-%d %H:%M:%S(?:\s*%Z)?\s')
self.filter.setMaxRetry(5); # don't ban here
self.filter.setMaxRetry(50); # don't ban here
self.filter.inOperation = True; # real processing (all messages are new)
# current time is 1h later than log-entries:
MyTime.setTime(1572138000+3600)
@ -476,36 +476,29 @@ class IgnoreIP(LogCaptureTestCase):
"Match without a timestamp:",
"192.0.2.17:1", "192.0.2.17:2", "192.0.2.17:3",
"Total # of detected failures: 9.", all=True, wait=True)
finally:
tearDownMyTime()
def testWrongTimeDelta(self):
try:
self.filter.addFailRegex('fail from <ADDR>$')
self.filter.setDatePattern(r'{^LN-BEG}%Y-%m-%d %H:%M:%S(?:\s*%Z)?\s')
self.filter.setMaxRetry(5); # don't ban here
self.filter.inOperation = True; # real processing (all messages are new)
expectable_messages = ["timezone problem.", "clock synchronization problem;", "latency problem."]
cases = [(-90*60, 0),
(-10*60, 1),
(-30, None),
(30, None),
(10*60, 2),
(90*60, 0)]
for idx, (delta, expect) in enumerate(cases):
#
phase = 3
for delta, expect in (
(-90*60, "timezone"), #90 minutes after
(-60*60, "timezone"), #60 minutes after
(-10*60, "timezone"), #10 minutes after
(-59, None), #59 seconds after
(59, None), #59 seconds before
(61, "latency"), #>1 minute before
(55*60, "latency"), #55 minutes before
(90*60, "timezone") #90 minutes before
):
phase += 1
MyTime.setTime(1572138000+delta)
setattr(self.filter, "_next_simByTimeWarn", -1)
self.pruneLog('[phase {phase}] log entries offset by {delta}s'.format(phase=idx+1, delta=delta))
for i in (1,2,3):
self.filter.processLineAndAdd('2019-10-27 02:00:00 fail from 192.0.2.15');
for (idx, msg) in enumerate(expectable_messages):
if idx == expect:
self.assertLogged(expectable_messages[idx])
else:
self.assertNotLogged(expectable_messages[idx])
self.assertLogged(
"192.0.2.15:1", "192.0.2.15:2", "192.0.2.15:3",
"Total # of detected failures: 3.", wait=True)
self.pruneLog('[phase {phase}] log entries offset by {delta}s'.format(phase=phase, delta=delta))
self.filter.processLineAndAdd('2019-10-27 02:00:00 fail from 192.0.2.15');
self.assertLogged("Found 192.0.2.15", wait=True)
if expect:
self.assertLogged(("timezone problem", "latency problem")[int(expect == "latency")], all=True)
self.assertNotLogged(("timezone problem", "latency problem")[int(expect != "latency")])
else:
self.assertNotLogged("timezone problem", "latency problem", all=True)
finally:
tearDownMyTime()