Merge branch '0.10' into 0.11

pull/2093/head
sebres 2018-01-31 12:20:34 +01:00
commit 201ae0dac2
12 changed files with 232 additions and 60 deletions

View File

@ -66,6 +66,10 @@ ver. 0.10.3-dev-1 (20??/??/??) - development edition
### New Features
### Enhancements
* date-detector extended with long epoch (`LEPOCH`) to parse milliseconds/microseconds posix-dates (gh-2029);
* possibility to specify own regex-pattern to match epoch date-time, e. g. `^\[{EPOCH}\]` or `^\[{LEPOCH}\]` (gh-2038);
the epoch-pattern similar to `{DATE}` patterns does the capture and cuts out the match of whole pattern from the log-line,
e. g. date-pattern `^\[{LEPOCH}\]\s+:` will match and cut out `[1516469849551000] :` from begin of the log-line.
ver. 0.10.2 (2018/01/18) - nothing-burns-like-the-cold

View File

@ -54,7 +54,7 @@ actioncheck =
# Tags: See jail.conf(5) man page
# Values: CMD
#
actionban = curl --fail --data-urlencode 'server=<email>' --data 'apikey=<apikey>' --data 'service=<service>' --data 'ip=<ip>' --data-urlencode 'logs=<matches>' --data 'format=text' --user-agent "<agent>" "https://www.blocklist.de/en/httpreports.html"
actionban = curl --fail --data-urlencode "server=<email>" --data "apikey=<apikey>" --data "service=<service>" --data "ip=<ip>" --data-urlencode "logs=<matches><br>" --data 'format=text' --user-agent "<agent>" "https://www.blocklist.de/en/httpreports.html"
# Option: actionunban
# Notes.: command executed when unbanning an IP. Take care that the
@ -64,8 +64,6 @@ actionban = curl --fail --data-urlencode 'server=<email>' --data 'apikey=<apikey
#
actionunban =
[Init]
# Option: email
# Notes server email address, as per blocklise.de account
# Values: STRING Default: None

View File

@ -33,7 +33,7 @@ if sys.version_info >= (3,2):
# SafeConfigParser deprecated from Python 3.2 (renamed to ConfigParser)
from configparser import ConfigParser as SafeConfigParser, BasicInterpolation, \
InterpolationMissingOptionError, NoSectionError
InterpolationMissingOptionError, NoOptionError, NoSectionError
# And interpolation of __name__ was simply removed, thus we need to
# decorate default interpolator to handle it
@ -63,7 +63,7 @@ if sys.version_info >= (3,2):
else: # pragma: no cover
from ConfigParser import SafeConfigParser, \
InterpolationMissingOptionError, NoSectionError
InterpolationMissingOptionError, NoOptionError, NoSectionError
# Interpolate missing known/option as option from default section
SafeConfigParser._cp_interpolate_some = SafeConfigParser._interpolate_some
@ -112,6 +112,8 @@ after = 1.conf
SECTION_NAME = "INCLUDES"
SECTION_OPTNAME_CRE = re.compile(r'^([\w\-]+)/([^\s>]+)$')
SECTION_OPTSUBST_CRE = re.compile(r'%\(([\w\-]+/([^\)]+))\)s')
CONDITIONAL_RE = re.compile(r"^(\w+)(\?.+)$")
@ -131,7 +133,36 @@ after = 1.conf
SafeConfigParser.__init__(self, *args, **kwargs)
self._cfg_share = share_config
def _map_section_options(self, section, option, rest, map):
def get_ex(self, section, option, raw=False, vars={}):
"""Get an option value for a given section.
In opposite to `get`, it differentiate session-related option name like `sec/opt`.
"""
sopt = None
# if option name contains section:
if '/' in option:
sopt = SafeConfigParserWithIncludes.SECTION_OPTNAME_CRE.search(option)
# try get value from named section/option:
if sopt:
sec = sopt.group(1)
opt = sopt.group(2)
seclwr = sec.lower()
if seclwr == 'known':
# try get value firstly from known options, hereafter from current section:
sopt = ('KNOWN/'+section, section)
else:
sopt = (sec,) if seclwr != 'default' else ("DEFAULT",)
for sec in sopt:
try:
v = self.get(sec, opt, raw=raw)
return v
except (NoSectionError, NoOptionError) as e:
pass
# get value of section/option using given section and vars (fallback):
v = self.get(section, option, raw=raw, vars=vars)
return v
def _map_section_options(self, section, option, rest, defaults):
"""
Interpolates values of the section options (name syntax `%(section/option)s`).
@ -139,37 +170,54 @@ after = 1.conf
"""
if '/' not in rest or '%(' not in rest: # pragma: no cover
return 0
rplcmnt = 0
soptrep = SafeConfigParserWithIncludes.SECTION_OPTSUBST_CRE.findall(rest)
if not soptrep: # pragma: no cover
return 0
for sopt, opt in soptrep:
if sopt not in map:
if sopt not in defaults:
sec = sopt[:~len(opt)]
seclwr = sec.lower()
if seclwr != 'default':
usedef = 0
if seclwr == 'known':
# try get raw value from known options:
try:
v = self._sections['KNOWN/'+section][opt]
except KeyError:
# fallback to default:
try:
v = self._defaults[opt]
except KeyError: # pragma: no cover
continue
usedef = 1
else:
# get raw value of opt in section:
v = self.get(sec, opt, raw=True)
try:
# if section not found - ignore:
try:
sec = self._sections[sec]
except KeyError: # pragma: no cover
continue
v = sec[opt]
except KeyError: # pragma: no cover
# fallback to default:
usedef = 1
else:
usedef = 1
if usedef:
try:
v = self._defaults[opt]
except KeyError: # pragma: no cover
continue
self._defaults[sopt] = v
try: # for some python versions need to duplicate it in map-vars also:
map[sopt] = v
except: pass
return 1
# replacement found:
rplcmnt = 1
try: # set it in map-vars (consider different python versions):
defaults[sopt] = v
except:
# try to set in first default map (corresponding vars):
try:
defaults._maps[0][sopt] = v
except: # pragma: no cover
# no way to update vars chain map - overwrite defaults:
self._defaults[sopt] = v
return rplcmnt
@property
def share_config(self):

View File

@ -351,7 +351,7 @@ class DefinitionInitConfigReader(ConfigReader):
return self._defCache[optname]
except KeyError:
try:
v = self.get("Definition", optname, vars=self._pOpts)
v = self._cfg.get_ex("Definition", optname, vars=self._pOpts)
except (NoSectionError, NoOptionError, ValueError):
v = None
self._defCache[optname] = v

View File

@ -26,7 +26,8 @@ import time
from threading import Lock
from .datetemplate import re, DateTemplate, DatePatternRegex, DateTai64n, DateEpoch
from .datetemplate import re, DateTemplate, DatePatternRegex, DateTai64n, DateEpoch, \
RE_EPOCH_PATTERN
from .strptime import validateTimeZone
from .utils import Utils
from ..helpers import getLogger
@ -36,7 +37,7 @@ logSys = getLogger(__name__)
logLevel = 6
RE_DATE_PREMATCH = re.compile("\{DATE\}", re.IGNORECASE)
RE_DATE_PREMATCH = re.compile(r"(?<!\\)\{DATE\}", re.IGNORECASE)
DD_patternCache = Utils.Cache(maxCount=1000, maxTime=60*60)
@ -48,12 +49,18 @@ def _getPatternTemplate(pattern, key=None):
template = DD_patternCache.get(key)
if not template:
if key in ("EPOCH", "{^LN-BEG}EPOCH", "^EPOCH"):
template = DateEpoch(lineBeginOnly=(key != "EPOCH"))
elif key in ("TAI64N", "{^LN-BEG}TAI64N", "^TAI64N"):
template = DateTai64n(wordBegin=('start' if key != "TAI64N" else False))
else:
template = DatePatternRegex(pattern)
if "EPOCH" in key:
if RE_EPOCH_PATTERN.search(pattern):
template = DateEpoch(pattern=pattern, longFrm="LEPOCH" in key)
elif key in ("EPOCH", "{^LN-BEG}EPOCH", "^EPOCH"):
template = DateEpoch(lineBeginOnly=(key != "EPOCH"))
elif key in ("LEPOCH", "{^LN-BEG}LEPOCH", "^LEPOCH"):
template = DateEpoch(lineBeginOnly=(key != "LEPOCH"), longFrm=True)
if template is None:
if key in ("TAI64N", "{^LN-BEG}TAI64N", "^TAI64N"):
template = DateTai64n(wordBegin=('start' if key != "TAI64N" else False))
else:
template = DatePatternRegex(pattern)
DD_patternCache.set(key, template)
return template

View File

@ -47,6 +47,9 @@ RE_LINE_BOUND_END = re.compile(r'(?<![\\\|])(?:\$\)?)$')
RE_ALPHA_PATTERN = re.compile(r'(?<!\%)\%[aAbBpc]')
RE_EPOCH_PATTERN = re.compile(r"(?<!\\)\{L?EPOCH\}", re.IGNORECASE)
class DateTemplate(object):
"""A template which searches for and returns a date from a log line.
@ -192,14 +195,25 @@ class DateEpoch(DateTemplate):
regex
"""
def __init__(self, lineBeginOnly=False):
def __init__(self, lineBeginOnly=False, pattern=None, longFrm=False):
DateTemplate.__init__(self)
self.name = "Epoch"
if not lineBeginOnly:
regex = r"((?:^|(?P<square>(?<=^\[))|(?P<selinux>(?<=\baudit\()))\d{10,11}\b(?:\.\d{3,6})?)(?:(?(selinux)(?=:\d+\)))|(?(square)(?=\])))"
self._longFrm = longFrm;
self._grpIdx = 1
epochRE = r"\d{10,11}\b(?:\.\d{3,6})?"
if longFrm:
self.name = "LongEpoch";
epochRE = r"\d{10,11}(?:\d{3}(?:\.\d{1,6}|\d{3})?)?"
if pattern:
# pattern should capture/cut out the whole match:
regex = "(" + RE_EPOCH_PATTERN.sub(lambda v: "(%s)" % epochRE, pattern) + ")"
self._grpIdx = 2
self.setRegex(regex)
elif not lineBeginOnly:
regex = r"((?:^|(?P<square>(?<=^\[))|(?P<selinux>(?<=\baudit\()))%s)(?:(?(selinux)(?=:\d+\)))|(?(square)(?=\])))" % epochRE
self.setRegex(regex, wordBegin=False) ;# already line begin resp. word begin anchored
else:
regex = r"((?P<square>(?<=^\[))?\d{10,11}\b(?:\.\d{3,6})?)(?(square)(?=\]))"
regex = r"((?P<square>(?<=^\[))?%s)(?(square)(?=\]))" % epochRE
self.setRegex(regex, wordBegin='start', wordEnd=True)
def getDate(self, line, dateMatch=None, default_tz=None):
@ -220,8 +234,14 @@ class DateEpoch(DateTemplate):
if not dateMatch:
dateMatch = self.matchDate(line)
if dateMatch:
v = dateMatch.group(self._grpIdx)
# extract part of format which represents seconds since epoch
return (float(dateMatch.group(1)), dateMatch)
if self._longFrm and len(v) >= 13:
if len(v) >= 16 and '.' not in v:
v = float(v) / 1000000
else:
v = float(v) / 1000
return (float(v), dateMatch)
class DatePatternRegex(DateTemplate):

View File

@ -188,7 +188,7 @@ y = %(jail/y)s
self.assertEqual(self.c.get('jail', 'c'), 'def-c,b:"jail-b-test-b-def-b,a:`jail-a-test-a-def-a`"')
self.assertEqual(self.c.get('jail', 'd'), 'def-d-b:"def-b,a:`jail-a-test-a-def-a`"')
self.assertEqual(self.c.get('test', 'c'), 'def-c,b:"test-b-def-b,a:`test-a-def-a`"')
self.assertEqual(self.c.get('test', 'd'), 'def-d-b:"def-b,a:`test-a-def-a`"')
self.assertEqual(self.c.get('test', 'd'), 'def-d-b:"def-b,a:`test-a-def-a`"')
self.assertEqual(self.c.get('DEFAULT', 'c'), 'def-c,b:"def-b,a:`def-a`"')
self.assertEqual(self.c.get('DEFAULT', 'd'), 'def-d-b:"def-b,a:`def-a`"')
self.assertRaises(Exception, self.c.get, 'test', 'x')
@ -437,9 +437,20 @@ class FilterReaderTest(unittest.TestCase):
self.assertSortedEqual(c, output)
def testFilterReaderSubstitionKnown(self):
output = [['set', 'jailname', 'addfailregex', 'to=test,sweet@example.com,test2,sweet@example.com fromip=<IP>']]
output = [['set', 'jailname', 'addfailregex', '^to=test,sweet@example.com,test2,sweet@example.com fromip=<IP>$']]
filterName, filterOpt = extractOptions(
'substition[honeypot="<sweet>,<known/honeypot>", sweet="test,<known/honeypot>,test2"]')
'substition[failregex="^<known/failregex>$", honeypot="<sweet>,<known/honeypot>", sweet="test,<known/honeypot>,test2"]')
filterReader = FilterReader('substition', "jailname", filterOpt,
share_config=TEST_FILES_DIR_SHARE_CFG, basedir=TEST_FILES_DIR)
filterReader.read()
filterReader.getOptions(None)
c = filterReader.convert()
self.assertSortedEqual(c, output)
def testFilterReaderSubstitionSection(self):
output = [['set', 'jailname', 'addfailregex', '^\s*to=fail2ban@localhost fromip=<IP>\s*$']]
filterName, filterOpt = extractOptions(
'substition[failregex="^\s*<Definition/failregex>\s*$", honeypot="<default/honeypot>"]')
filterReader = FilterReader('substition', "jailname", filterOpt,
share_config=TEST_FILES_DIR_SHARE_CFG, basedir=TEST_FILES_DIR)
filterReader.read()

View File

@ -77,6 +77,48 @@ class DateDetectorTest(LogCaptureTestCase):
log = date + " [sshd] error: PAM: Authentication failure"
datelog = self.datedetector.getTime(log)
self.assertFalse(datelog)
def testGetEpochMsTime(self):
self.__datedetector = DateDetector()
self.__datedetector.appendTemplate('LEPOCH')
# correct short/long epoch time, using all variants:
for fact in (1, 1000, 1000000):
for dateUnix in (1138049999, 32535244799):
for date in ("%s", "[%s]", "[%s]", "audit(%s:101)"):
dateLong = dateUnix * fact
date = date % dateLong
log = date + " [sshd] error: PAM: Authentication failure"
datelog = self.datedetector.getTime(log)
self.assertTrue(datelog, "Parse epoch time for %s failed" % (date,))
( datelog, matchlog ) = datelog
self.assertEqual(int(datelog), dateUnix)
self.assertEqual(matchlog.group(1), str(dateLong))
# wrong, no epoch time (< 10 digits, more as 17 digits, begin/end of word) :
for dateUnix in ('123456789', '999999999999999999', '1138049999A', 'A1138049999'):
for date in ("%s", "[%s]", "[%s.555]", "audit(%s.555:101)"):
date = date % dateUnix
log = date + " [sshd] error: PAM: Authentication failure"
datelog = self.datedetector.getTime(log)
self.assertFalse(datelog)
def testGetEpochPattern(self):
self.__datedetector = DateDetector()
self.__datedetector.appendTemplate('(?<=\|\s){LEPOCH}(?=\s\|)')
# correct short/long epoch time, using all variants:
for fact in (1, 1000, 1000000):
for dateUnix in (1138049999, 32535244799):
dateLong = dateUnix * fact
log = "auth-error | %s | invalid password" % dateLong
datelog = self.datedetector.getTime(log)
self.assertTrue(datelog, "Parse epoch time failed: %r" % (log,))
( datelog, matchlog ) = datelog
self.assertEqual(int(datelog), dateUnix)
self.assertEqual(matchlog.group(1), str(dateLong))
# wrong epoch time format (does not match pattern):
for log in ("test%s123", "test-right | %stest", "test%s | test-left"):
log = log % dateLong
datelog = self.datedetector.getTime(log)
self.assertFalse(datelog)
def testGetTime(self):
log = "Jan 23 21:59:59 [sshd] error: PAM: Authentication failure"

View File

@ -347,7 +347,7 @@ def with_foreground_server_thread(startextra={}):
Utils.wait_for(lambda: phase.get('start', None) is not None, MAX_WAITTIME)
self.assertTrue(phase.get('start', None))
# wait for server (socket and ready):
self._wait_for_srv(tmp, True, startparams=startparams)
self._wait_for_srv(tmp, True, startparams=startparams, phase=phase)
DefLogSys.info('=== within server: begin ===')
self.pruneLog()
# several commands to server in body of decorated function:
@ -399,12 +399,12 @@ class Fail2banClientServerBase(LogCaptureTestCase):
else:
raise FailExitException()
def _wait_for_srv(self, tmp, ready=True, startparams=None):
def _wait_for_srv(self, tmp, ready=True, startparams=None, phase={}):
try:
sock = pjoin(tmp, "f2b.sock")
# wait for server (socket):
ret = Utils.wait_for(lambda: exists(sock), MAX_WAITTIME)
if not ret:
ret = Utils.wait_for(lambda: phase.get('end') or exists(sock), MAX_WAITTIME)
if not ret or phase.get('end'): # pragma: no cover - test-failure case only
raise Exception(
'Unexpected: Socket file does not exists.\nStart failed: %r'
% (startparams,)
@ -412,7 +412,7 @@ class Fail2banClientServerBase(LogCaptureTestCase):
if ready:
# wait for communication with worker ready:
ret = Utils.wait_for(lambda: "Server ready" in self.getLog(), MAX_WAITTIME)
if not ret:
if not ret: # pragma: no cover - test-failure case only
raise Exception(
'Unexpected: Server ready was not found.\nStart failed: %r'
% (startparams,)
@ -436,10 +436,12 @@ class Fail2banClientServerBase(LogCaptureTestCase):
# start and wait to end (foreground):
logSys.debug("start of test worker")
phase['start'] = True
self.execCmd(SUCCESS, ("-f",) + startparams, "start")
# end :
phase['end'] = True
logSys.debug("end of test worker")
try:
self.execCmd(SUCCESS, ("-f",) + startparams, "start")
finally:
# end :
phase['end'] = True
logSys.debug("end of test worker")
@with_foreground_server_thread()
def testStartForeground(self, tmp, startparams):
@ -1206,7 +1208,7 @@ class Fail2banServerTest(Fail2banClientServerBase):
@with_foreground_server_thread(startextra={
# create log-file (avoid "not found" errors):
'create_before_start': ('%(tmp)s/blck-failures.log',),
# we need action.d/nginx-block-map.conf:
# we need action.d/nginx-block-map.conf and blocklist_de:
'use_stock_cfg': ('action.d',),
# jail-config:
'jails': (
@ -1215,6 +1217,8 @@ class Fail2banServerTest(Fail2banClientServerBase):
'usedns = no',
'logpath = %(tmp)s/blck-failures.log',
'action = nginx-block-map[blck_lst_reload="", blck_lst_file="%(tmp)s/blck-lst.map"]',
' blocklist_de[actionban=\'curl() { echo "*** curl" "$*";}; <Definition/actionban>\', email="Fail2Ban <fail2ban@localhost>", '
'apikey="TEST-API-KEY", agent="fail2ban-test-agent", service=<name>]',
'filter =',
'datepattern = ^Epoch',
'failregex = ^ failure "<F-ID>[^"]+</F-ID>" - <ADDR>',
@ -1252,6 +1256,14 @@ class Fail2banServerTest(Fail2banClientServerBase):
self.assertIn('\\125-000-004 1;\n', mp)
self.assertIn('\\125-000-005 1;\n', mp)
# check blocklist_de substitution (e. g. new-line after <matches>):
self.assertLogged(
"stdout: '*** curl --fail --data-urlencode server=Fail2Ban <fail2ban@localhost>"
" --data apikey=TEST-API-KEY --data service=nginx-blck-lst ",
"stdout: ' --data format=text --user-agent fail2ban-test-agent",
all=True, wait=MID_WAITTIME
)
# unban 1, 2 and 5:
self.execCmd(SUCCESS, startparams, 'unban', '125-000-001', '125-000-002', '125-000-005')
_out_file(mpfn)

View File

@ -290,6 +290,17 @@ class Fail2banRegexTest(LogCaptureTestCase):
self.assertTrue(fail2banRegex.start(args))
self.assertLogged('Lines: 1 lines, 0 ignored, 1 matched, 0 missed')
def testRegexEpochPatterns(self):
(opts, args, fail2banRegex) = _Fail2banRegex(
"-r", "-d", "^\[{LEPOCH}\]\s+", "--maxlines", "5",
"[1516469849] 192.0.2.1 FAIL: failure\n"
"[1516469849551] 192.0.2.2 FAIL: failure\n"
"[1516469849551000] 192.0.2.3 FAIL: failure\n"
"[1516469849551.000] 192.0.2.4 FAIL: failure",
r"^<HOST> FAIL\b"
)
self.assertTrue(fail2banRegex.start(args))
self.assertLogged('Lines: 4 lines, 0 ignored, 4 matched, 0 missed')
def testWrongFilterFile(self):
# use test log as filter file to cover eror cases...

View File

@ -1,3 +1,6 @@
[DEFAULT]
honeypot = fail2ban@localhost
[Definition]

View File

@ -644,7 +644,9 @@ class LogCaptureTestCase(unittest.TestCase):
def __init__(self, lazy=True):
self._lock = threading.Lock()
self._val = None
self._dirty = True
self._recs = list()
self._nolckCntr = 0
self._strm = StringIO()
logging.Handler.__init__(self)
if lazy:
@ -654,10 +656,11 @@ class LogCaptureTestCase(unittest.TestCase):
"""Truncate the internal buffer and records."""
if size:
raise Exception('invalid size argument: %r, should be None or 0' % size)
self._val = None
self._dirty = True
with self._lock:
self._strm.truncate(0)
self._val = None
self._recs = list()
self._strm.truncate(0)
def __write(self, record):
msg = record.getMessage() + '\n'
@ -668,29 +671,42 @@ class LogCaptureTestCase(unittest.TestCase):
def getvalue(self):
"""Return current buffer as whole string."""
with self._lock:
# cached:
if self._val is not None:
return self._val
# submit already emitted (delivered to handle) records:
for record in self._recs:
self.__write(record)
self._recs = list()
# cache and return:
self._val = self._strm.getvalue()
# if cached (still unchanged/no write operation), we don't need to enter lock:
if not self._dirty:
return self._val
# try to lock, if not possible - return cached/empty (max 5 times):
lck = self._lock.acquire(False)
if not lck: # pargma: no cover (may be too sporadic on slow systems)
self._nolckCntr += 1
if self._nolckCntr <= 5:
return self._val if self._val is not None else ''
self._nolckCntr = 0
self._lock.acquire()
# minimize time of lock, avoid dead-locking during cross lock within self._strm ...
try:
recs = self._recs
self._recs = list()
finally:
self._lock.release()
# submit already emitted (delivered to handle) records:
for record in recs:
self.__write(record)
# cache and return:
self._val = self._strm.getvalue()
self._dirty = False
return self._val
def handle(self, record): # pragma: no cover
"""Handle the specified record direct (not lazy)"""
with self._lock:
self._val = None
self.__write(record)
self.__write(record)
self._dirty = True
def _handle_lazy(self, record):
"""Lazy handle the specified record on demand"""
with self._lock:
self._val = None
self._recs.append(record)
# logged - causes changed string buffer (signal by set _dirty):
self._dirty = True
def setUp(self):