From c7ae74ce178adb819cdb3342a248c4e30346bd33 Mon Sep 17 00:00:00 2001 From: sebres Date: Tue, 8 Feb 2022 19:10:22 +0100 Subject: [PATCH 1/6] amend to a147a8b0e1b2f32b6f191932afd3c2db9765e2e3: systemd journal test-cases - additional check appropriate default settings (if testing as not root/sudoer) --- fail2ban/tests/filtertestcase.py | 14 +++++++++----- 1 file changed, 9 insertions(+), 5 deletions(-) diff --git a/fail2ban/tests/filtertestcase.py b/fail2ban/tests/filtertestcase.py index 32dcca5c..f9fa5e97 100644 --- a/fail2ban/tests/filtertestcase.py +++ b/fail2ban/tests/filtertestcase.py @@ -1352,7 +1352,6 @@ def get_monitor_failures_journal_testcase(Filter_): # pragma: systemd no cover def setUp(self): """Call before every test case.""" super(MonitorJournalFailures, self).setUp() - self._runtimeJournal = None self.test_file = os.path.join(TEST_FILES_DIR, "testcase-journal.log") self.jail = DummyJail() self.filter = None @@ -1390,7 +1389,7 @@ def get_monitor_failures_journal_testcase(Filter_): # pragma: systemd no cover If not found, SkipTest exception will be raised. """ # we can cache it: - if self._runtimeJournal is None: + if not hasattr(MonitorJournalFailures, "_runtimeJournal"): # Depending on the system, it could be found under /run or /var/log (e.g. Debian) # which are pointed by different systemd-path variables. We will # check one at at time until the first hit @@ -1402,9 +1401,14 @@ def get_monitor_failures_journal_testcase(Filter_): # pragma: systemd no cover self.assertTrue(tmp) out = str(tmp[1].decode('utf-8')).split('\n')[0] if out: break - self._runtimeJournal = out - if self._runtimeJournal: - return self._runtimeJournal + # additional check appropriate default settings (if not root/sudoer and not already set): + if os.geteuid() != 0 and os.getenv("F2B_SYSTEMD_DEFAULT_FLAGS", None) is None: + # filter default SYSTEM_ONLY(4) is hardly usable for not root/sudoer tester, + # so back to default LOCAL_ONLY(1): + os.environ["F2B_SYSTEMD_DEFAULT_FLAGS"] = "0"; # or "1", what will be similar to journalflags=0 or ...=1 + MonitorJournalFailures._runtimeJournal = out + if MonitorJournalFailures._runtimeJournal: + return MonitorJournalFailures._runtimeJournal raise unittest.SkipTest('systemd journal seems to be not available (e. g. no rights to read)') def testJournalFilesArg(self): From 810386a265d621a0af9f4917f68fae9bf95d1ba4 Mon Sep 17 00:00:00 2001 From: sebres Date: Tue, 8 Feb 2022 19:21:37 +0100 Subject: [PATCH 2/6] filter.d/dovecot.conf: parse everything in parenthesis by auth-worker info, e. g. can match (pid=...,uid=...) too (amend to 92f90038fa67d719c55c75f5eff8059e849fe747) --- config/filter.d/dovecot.conf | 2 +- fail2ban/tests/files/logs/dovecot | 5 +++++ 2 files changed, 6 insertions(+), 1 deletion(-) diff --git a/config/filter.d/dovecot.conf b/config/filter.d/dovecot.conf index 9c817720..b1df82f2 100644 --- a/config/filter.d/dovecot.conf +++ b/config/filter.d/dovecot.conf @@ -8,7 +8,7 @@ before = common.conf [Definition] _auth_worker = (?:dovecot: )?auth(?:-worker)? -_auth_worker_info = (?:conn \w+:auth(?:-worker)? \(uid=\w+\): auth(?:-worker)?<\d+>: )? +_auth_worker_info = (?:conn \w+:auth(?:-worker)? \([^\)]+\): auth(?:-worker)?<\d+>: )? _daemon = (?:dovecot(?:-auth)?|auth) prefregex = ^%(__prefix_line)s(?:%(_auth_worker)s(?:\([^\)]+\))?: )?(?:%(__pam_auth)s(?:\(dovecot:auth\))?: |(?:pop3|imap|managesieve|submission)-login: )?(?:Info: )?%(_auth_worker_info)s.+$ diff --git a/fail2ban/tests/files/logs/dovecot b/fail2ban/tests/files/logs/dovecot index 6bcf8c5b..7649cfeb 100644 --- a/fail2ban/tests/files/logs/dovecot +++ b/fail2ban/tests/files/logs/dovecot @@ -60,6 +60,11 @@ Jun 12 11:48:12 auth-worker(80180): Info: conn unix:auth-worker (uid=143): auth- # failJSON: { "time": "2005-06-12T23:06:05", "match": true , "host": "192.0.2.7" } Jun 12 23:06:05 auth-worker(57065): Info: conn unix:auth-worker (uid=143): auth-worker<225622>: sql(user@domain.com,192.0.2.7,): Password mismatch +# failJSON: { "time": "2005-06-15T11:28:21", "match": true , "host": "192.0.2.7" } +Jun 15 11:28:21 hostname dovecot: auth-worker(5787): conn unix:auth-worker (pid=27359,uid=97): auth-worker<55>: pam(webapps,192.0.2.7): unknown user +# failJSON: { "time": "2005-06-15T13:57:41", "match": true , "host": "192.0.2.7" } +Jun 15 13:57:41 hostname dovecot: auth-worker(3270): conn unix:auth-worker (pid=27359,uid=97): auth-worker<128>: pam(webapps,192.0.2.7): pam_authenticate() failed: Authentication failure (Password mismatch?) + # failJSON: { "time": "2005-01-29T14:38:51", "match": true , "host": "192.0.2.6", "desc": "PAM Permission denied (gh-1897)" } Jan 29 14:38:51 example.com dovecot[24941]: auth-worker(30165): pam(user@example.com,192.0.2.6,): pam_authenticate() failed: Permission denied From 8013cf0b900f2cacfdc1c9152c9b9847bfc41877 Mon Sep 17 00:00:00 2001 From: sebres Date: Tue, 8 Feb 2022 19:57:40 +0100 Subject: [PATCH 3/6] python actions have no attribute 'consistencyCheck' by default; closes gh-3214 --- fail2ban/server/actions.py | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/fail2ban/server/actions.py b/fail2ban/server/actions.py index 897d907c..eb14c14f 100644 --- a/fail2ban/server/actions.py +++ b/fail2ban/server/actions.py @@ -513,9 +513,10 @@ class Actions(JailThread, Mapping): if bTicket.banEpoch == self.banEpoch and diftm > 3: # avoid too often checks: if not rebanacts and MyTime.time() > self.__lastConsistencyCheckTM + 3: - for action in self._actions.itervalues(): - action.consistencyCheck() self.__lastConsistencyCheckTM = MyTime.time() + for action in self._actions.itervalues(): + if hasattr(action, 'consistencyCheck'): + action.consistencyCheck() # check epoch in order to reban it: if bTicket.banEpoch < self.banEpoch: if not rebanacts: rebanacts = dict( From 498e473a10ee56aa6345b03cd3bf83e017df966c Mon Sep 17 00:00:00 2001 From: sebres Date: Wed, 9 Feb 2022 12:18:23 +0100 Subject: [PATCH 4/6] filter.d/courier-auth.conf: consider optional port after IP, regex is rewritten without catch-all's and right anchor, so it is more stable against further modifications now; closes #3211 --- config/filter.d/courier-auth.conf | 2 +- fail2ban/tests/files/logs/courier-auth | 2 ++ 2 files changed, 3 insertions(+), 1 deletion(-) diff --git a/config/filter.d/courier-auth.conf b/config/filter.d/courier-auth.conf index 1ac33736..d5ba9c50 100644 --- a/config/filter.d/courier-auth.conf +++ b/config/filter.d/courier-auth.conf @@ -11,7 +11,7 @@ before = common.conf _daemon = (?:courier)?(?:imapd?|pop3d?)(?:login)?(?:-ssl)? -failregex = ^%(__prefix_line)sLOGIN FAILED, (?:user|method)=.*, ip=\[\]$ +failregex = ^%(__prefix_line)sLOGIN FAILED, (?:(?!ip=)(?:user=[^,]*|\w+=[^,]*), )*ip=\[\] ignoreregex = diff --git a/fail2ban/tests/files/logs/courier-auth b/fail2ban/tests/files/logs/courier-auth index 3505e109..8a20a27f 100644 --- a/fail2ban/tests/files/logs/courier-auth +++ b/fail2ban/tests/files/logs/courier-auth @@ -8,3 +8,5 @@ Nov 13 08:11:53 server imapd-ssl: LOGIN FAILED, user=user@domain.tld, ip=[::ffff Apr 17 19:17:11 SERVER courierpop3login: LOGIN FAILED, user=USER@EXAMPLE.org, ip=[::ffff:1.2.3.4] # failJSON: { "time": "2005-04-17T19:17:12", "match": true , "host": "192.0.2.4" } Apr 17 19:17:12 server imapd-ssl: LOGIN FAILED, method=PLAIN, ip=[::ffff:192.0.2.4] +# failJSON: { "time": "2005-04-27T09:00:00", "match": true , "user": "tester", "host": "192.0.2.5" } +Apr 27 09:00:00 servername imapd: LOGIN FAILED, user=tester, ip=[::ffff:192.0.2.5], port=[255] From cdb6a46945455ac49bce7efda25046140babcf9c Mon Sep 17 00:00:00 2001 From: sebres Date: Wed, 9 Feb 2022 14:47:40 +0100 Subject: [PATCH 5/6] systemd backend: better avoidance of landing in dead space by seeks over journals; increase verbosity and stability of few systemd tests (fixes sporadic timing issues); seekToTime doesn't need to convert float to datetime, because seek_realtime accepts it as unix time (we need to convert integers only, since it means microseconds and deprecated); --- fail2ban/server/filtersystemd.py | 21 +++++++++++---------- fail2ban/tests/filtertestcase.py | 30 +++++++++++++++++++----------- 2 files changed, 30 insertions(+), 21 deletions(-) diff --git a/fail2ban/server/filtersystemd.py b/fail2ban/server/filtersystemd.py index 6301b93a..8c67eedc 100644 --- a/fail2ban/server/filtersystemd.py +++ b/fail2ban/server/filtersystemd.py @@ -22,7 +22,6 @@ __author__ = "Steven Hiscocks" __copyright__ = "Copyright (c) 2013 Steven Hiscocks" __license__ = "GPL" -import datetime import os import time from distutils.version import LooseVersion @@ -254,8 +253,8 @@ class FilterSystemd(JournalFilter): # pragma: systemd no cover return ((logline[:0], date[0], logline.replace('\n', '\\n')), date[1]) def seekToTime(self, date): - if not isinstance(date, datetime.datetime): - date = datetime.datetime.fromtimestamp(date) + if isinstance(date, (int, long)): + date = float(date) self.__journal.seek_realtime(date) def inOperationMode(self): @@ -281,7 +280,8 @@ class FilterSystemd(JournalFilter): # pragma: systemd no cover try: self.__journal.seek_tail() logentry = self.__journal.get_previous() - self.__journal.get_next() + if logentry: + self.__journal.get_next() except OSError: logentry = None # Reading failure, so safe to ignore if logentry: @@ -296,12 +296,6 @@ class FilterSystemd(JournalFilter): # pragma: systemd no cover self.inOperation = False # Save current time in order to check time to switch "in operation" mode startTime = (1, MyTime.time(), logentry.get('__CURSOR')) - # Move back one entry to ensure do not end up in dead space - # if start time beyond end of journal - try: - self.__journal.get_previous() - except OSError: - pass # Reading failure, so safe to ignore else: # empty journal or no entries for current filter: self.inOperationMode() @@ -311,6 +305,13 @@ class FilterSystemd(JournalFilter): # pragma: systemd no cover # for possible future switches of in-operation mode: startTime = (0, startTime) + # Move back one entry to ensure do not end up in dead space + # if start time beyond end of journal + try: + self.__journal.get_previous() + except OSError: + pass # Reading failure, so safe to ignore + line = None while self.active: # wait for records (or for timeout in sleeptime seconds): diff --git a/fail2ban/tests/filtertestcase.py b/fail2ban/tests/filtertestcase.py index f9fa5e97..a9641eee 100644 --- a/fail2ban/tests/filtertestcase.py +++ b/fail2ban/tests/filtertestcase.py @@ -1514,7 +1514,7 @@ def get_monitor_failures_journal_testcase(Filter_): # pragma: systemd no cover # stop: self.filter.stop() self.filter.join() - MyTime.setTime(time.time() + 2) + MyTime.setTime(time.time() + 10) # update log manually (should cause a seek to end of log without wait for next second): self.jail.database.updateJournal(self.jail, 'systemd-journal', MyTime.time(), 'TEST') # check seek to last (simulated) position succeeds (without bans of previous copied tickets): @@ -1522,7 +1522,7 @@ def get_monitor_failures_journal_testcase(Filter_): # pragma: systemd no cover self._initFilter() self.filter.setMaxRetry(1) self.filter.start() - self.waitForTicks(1) + self.waitForTicks(2) # check new IP but no old IPs found: _gen_falure("192.0.2.5") self.assertFalse(self.jail.getFailTicket()) @@ -1535,8 +1535,8 @@ def get_monitor_failures_journal_testcase(Filter_): # pragma: systemd no cover self._initFilter() self.filter.setMaxRetry(1) self.filter.start() - self.waitForTicks(1) - MyTime.setTime(time.time() + 3) + self.waitForTicks(2) + MyTime.setTime(time.time() + 20) # check new IP but no old IPs found: _gen_falure("192.0.2.6") self.assertFalse(self.jail.getFailTicket()) @@ -1549,15 +1549,23 @@ def get_monitor_failures_journal_testcase(Filter_): # pragma: systemd no cover self.filter.setMaxRetry(1) states = [] def _state(*args): - self.assertNotIn("** in operation", states) - self.assertFalse(self.filter.inOperation) - states.append("** process line: %r" % (args,)) + try: + self.assertNotIn("** in operation", states) + self.assertFalse(self.filter.inOperation) + states.append("** process line: %r" % (args,)) + except Exception as e: + states.append("** failed: %r" % (e,)) + raise self.filter.processLineAndAdd = _state def _inoper(): - self.assertNotIn("** in operation", states) - self.assertEqual(len(states), 11) - states.append("** in operation") - self.filter.__class__.inOperationMode(self.filter) + try: + self.assertNotIn("** in operation", states) + self.assertEqual(len(states), 11) + states.append("** in operation") + self.filter.__class__.inOperationMode(self.filter) + except Exception as e: + states.append("** failed: %r" % (e,)) + raise self.filter.inOperationMode = _inoper self.filter.start() self.waitForTicks(12) From f380d6202d3760b3fbb718b5296061beec1787d0 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?L=C3=A1szl=C3=B3=20K=C3=A1rolyi?= Date: Thu, 27 Jan 2022 12:28:20 +0100 Subject: [PATCH 6/6] cherry pick #3210 from master --- config/filter.d/dovecot.conf | 2 +- fail2ban/tests/files/logs/dovecot | 2 ++ 2 files changed, 3 insertions(+), 1 deletion(-) diff --git a/config/filter.d/dovecot.conf b/config/filter.d/dovecot.conf index b1df82f2..0415ecb4 100644 --- a/config/filter.d/dovecot.conf +++ b/config/filter.d/dovecot.conf @@ -14,7 +14,7 @@ _daemon = (?:dovecot(?:-auth)?|auth) prefregex = ^%(__prefix_line)s(?:%(_auth_worker)s(?:\([^\)]+\))?: )?(?:%(__pam_auth)s(?:\(dovecot:auth\))?: |(?:pop3|imap|managesieve|submission)-login: )?(?:Info: )?%(_auth_worker_info)s.+$ failregex = ^authentication failure; logname=\S* uid=\S* euid=\S* tty=dovecot ruser=\S* rhost=(?:\s+user=\S*)?\s*$ - ^(?:Aborted login|Disconnected|Remote closed connection|Client has quit the connection)(?::(?: [^ \(]+)+)? \((?:auth failed, \d+ attempts(?: in \d+ secs)?|tried to use (?:disabled|disallowed) \S+ auth|proxy dest auth failed)\):(?: user=<[^>]*>,)?(?: method=\S+,)? rip=(?:[^>]*(?:, session=<\S+>)?)\s*$ + ^(?:Aborted login|Disconnected|Remote closed connection|Client has quit the connection)(?:: (?:[^\(]+|\w+\([^\)]*\))+)? \((?:auth failed, \d+ attempts(?: in \d+ secs)?|tried to use (?:disabled|disallowed) \S+ auth|proxy dest auth failed)\):(?: user=<[^>]*>,)?(?: method=\S+,)? rip=(?:[^>]*(?:, session=<\S+>)?)\s*$ ^pam\(\S+,(?:,\S*)?\): pam_authenticate\(\) failed: (?:User not known to the underlying authentication module: \d+ Time\(s\)|Authentication failure \([Pp]assword mismatch\?\)|Permission denied)\s*$ ^[a-z\-]{3,15}\(\S*,(?:,\S*)?\): (?:[Uu]nknown user|[Ii]nvalid credentials|[Pp]assword mismatch) > diff --git a/fail2ban/tests/files/logs/dovecot b/fail2ban/tests/files/logs/dovecot index 7649cfeb..75934c37 100644 --- a/fail2ban/tests/files/logs/dovecot +++ b/fail2ban/tests/files/logs/dovecot @@ -112,6 +112,8 @@ Jul 26 11:12:19 hostname dovecot: imap-login: Disconnected: Too many invalid com # failJSON: { "time": "2004-08-28T06:38:51", "match": true , "host": "192.0.2.3" } Aug 28 06:38:51 s166-62-100-187 dovecot: imap-login: Disconnected (auth failed, 1 attempts in 9 secs): user=, method=PLAIN, rip=192.0.2.3, lip=192.168.1.2, TLS: Disconnected, TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits) +# failJSON: { "time": "2004-08-28T06:38:52", "match": true , "host": "192.0.2.4", "desc": "open parenthesis in optional part between Disconnected and (auth failed ...), gh-3210" } +Aug 28 06:38:52 s166-62-100-187 dovecot: imap-login: Disconnected: Connection closed: read(size=1003) failed: Connection reset by peer (auth failed, 1 attempts in 0 secs): user=, rip=192.0.2.4, lip=127.0.0.19, session= # failJSON: { "time": "2004-08-29T03:17:18", "match": true , "host": "192.0.2.133" } Aug 29 03:17:18 server dovecot: submission-login: Client has quit the connection (auth failed, 1 attempts in 2 secs): user=, method=LOGIN, rip=192.0.2.133, lip=0.0.0.0