From bd54d472b37a98bed9bd503f95402e980aa4fcf2 Mon Sep 17 00:00:00 2001 From: sebres Date: Thu, 5 Jul 2018 16:23:33 +0200 Subject: [PATCH 1/6] extend test-cases to check the database is still operable (not locked) after all the errors during the simulation --- fail2ban/tests/databasetestcase.py | 8 ++++++++ 1 file changed, 8 insertions(+) diff --git a/fail2ban/tests/databasetestcase.py b/fail2ban/tests/databasetestcase.py index 8c154c92..cb8beecc 100644 --- a/fail2ban/tests/databasetestcase.py +++ b/fail2ban/tests/databasetestcase.py @@ -268,6 +268,7 @@ class DatabaseTest(LogCaptureTestCase): self.assertEqual(readtickets[i].getIP(), ticket.getIP()) self.assertEqual(len(readtickets[i].getMatches()), len(ticket.getMatches())) + self.pruneLog('[test-phase 2] simulate errors') ## simulate errors in dumps/loads: priorEnc = database.PREFER_ENC try: @@ -286,6 +287,13 @@ class DatabaseTest(LogCaptureTestCase): self.assertEqual(len(readtickets), 14) finally: database.PREFER_ENC = priorEnc + + ## check the database is still operable (not locked) after all the errors: + self.pruneLog('[test-phase 3] still operable?') + self.db.addBan(self.jail, FailTicket("127.0.0.8")) + readtickets = self.db.getBans(jail=self.jail) + self.assertEqual(len(readtickets), 15) + self.assertNotLogged("json loads failed", "json dumps failed") def _testAdd3Bans(self): self.testAddJail() From 6ce67a6d21fe546f00fd664d73b78725dfb67e86 Mon Sep 17 00:00:00 2001 From: sebres Date: Thu, 5 Jul 2018 16:27:36 +0200 Subject: [PATCH 2/6] coverage --- config/action.d/badips.py | 6 +++--- fail2ban/tests/action_d/test_badips.py | 4 ++-- 2 files changed, 5 insertions(+), 5 deletions(-) diff --git a/config/action.d/badips.py b/config/action.d/badips.py index 6a6760b5..4e50890c 100644 --- a/config/action.d/badips.py +++ b/config/action.d/badips.py @@ -18,16 +18,16 @@ # Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA. import sys -if sys.version_info < (2, 7): +if sys.version_info < (2, 7): # pragma: no cover raise ImportError("badips.py action requires Python >= 2.7") import json import threading import logging -if sys.version_info >= (3, ): +if sys.version_info >= (3, ): # pragma: 2.x no cover from urllib.request import Request, urlopen from urllib.parse import urlencode from urllib.error import HTTPError -else: +else: # pragma: 3.x no cover from urllib2 import Request, urlopen, HTTPError from urllib import urlencode diff --git a/fail2ban/tests/action_d/test_badips.py b/fail2ban/tests/action_d/test_badips.py index 1cc3b19d..3ea1fc76 100644 --- a/fail2ban/tests/action_d/test_badips.py +++ b/fail2ban/tests/action_d/test_badips.py @@ -29,9 +29,9 @@ from ..dummyjail import DummyJail from ..servertestcase import IPAddr from ..utils import LogCaptureTestCase, CONFIG_DIR -if sys.version_info >= (3, ): +if sys.version_info >= (3, ): # pragma: 2.x no cover from urllib.error import HTTPError, URLError -else: +else: # pragma: 3.x no cover from urllib2 import HTTPError, URLError def skip_if_not_available(f): From 06f2130575b4efb15516800d653b6a325622e7b8 Mon Sep 17 00:00:00 2001 From: sebres Date: Thu, 5 Jul 2018 19:27:07 +0200 Subject: [PATCH 3/6] typo/indent fix (no functional changes) --- fail2ban/helpers.py | 2 +- fail2ban/server/database.py | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/fail2ban/helpers.py b/fail2ban/helpers.py index 11dec5aa..3297375b 100644 --- a/fail2ban/helpers.py +++ b/fail2ban/helpers.py @@ -45,7 +45,7 @@ if PREFER_ENC.startswith('ANSI_'): # pragma: no cover # caused by implicit converting of string/unicode (e. g. `str(u"\uFFFD")` produces an error # if default encoding is 'ascii'); if sys.version_info < (3,): # pragma: 3.x no cover - # correct default (global system) encoding (mostly UTF-8): + # correct default (global system) encoding (mostly UTF-8): def __resetDefaultEncoding(encoding): global PREFER_ENC ode = sys.getdefaultencoding().upper() diff --git a/fail2ban/server/database.py b/fail2ban/server/database.py index 5536f1e6..26e0223d 100644 --- a/fail2ban/server/database.py +++ b/fail2ban/server/database.py @@ -40,7 +40,7 @@ logSys = getLogger(__name__) def _json_default(x): - """Avoid errors on types unknow in json-adapters.""" + """Avoid errors on types unknown in json-adapters.""" if isinstance(x, set): x = list(x) return uni_string(x) From bcf557990e15922aff22485cc86ddd2fcf41b796 Mon Sep 17 00:00:00 2001 From: sebres Date: Thu, 5 Jul 2018 22:35:35 +0200 Subject: [PATCH 4/6] relocate exception-safe logging from database json-handler to common logger handling, using injection on _log-method of Logger class; additionally provides more info if handler/conversion failed (with double protection inside catch-case); tests/utils.py: log handler "_MemHandler" of LogCaptureTestCase fixed now to be safe also (test-cases only); tests/misctestcase.py: the safe logging of all possible constellations is covered in testSafeLogging now. --- fail2ban/helpers.py | 29 +++++++++++++++++++++++ fail2ban/server/database.py | 28 +++++++---------------- fail2ban/tests/misctestcase.py | 42 ++++++++++++++++++++++++++++++++++ fail2ban/tests/utils.py | 11 +++++---- 4 files changed, 86 insertions(+), 24 deletions(-) diff --git a/fail2ban/helpers.py b/fail2ban/helpers.py index 3297375b..5681c31b 100644 --- a/fail2ban/helpers.py +++ b/fail2ban/helpers.py @@ -202,6 +202,35 @@ class FormatterWithTraceBack(logging.Formatter): return logging.Formatter.format(self, record) +__origLog = logging.Logger._log +def __safeLog(self, level, msg, args, **kwargs): + """Safe log inject to avoid possible errors by unsafe log-handlers, + concat, str. conversion, representation fails, etc. + + Used to intrude exception-safe _log-method instead of _log-method + of Logger class to be always safe by logging and to get more-info about. + + See testSafeLogging test-case for more information. At least the errors + covered in phase 3 seems to affected in all known pypy/python versions + until now. + """ + try: + # if isEnabledFor(level) already called... + __origLog(self, level, msg, args, **kwargs) + except Exception as e: # pragma: no cover - unreachable if log-handler safe in this python-version + try: + for args in ( + ("logging failed: %r on %s", (e, uni_string(msg))), + (" args: %r", ([uni_string(a) for a in args],)) + ): + try: + __origLog(self, level, *args) + except: # pragma: no cover + pass + except: # pragma: no cover + pass +logging.Logger._log = __safeLog + def getLogger(name): """Get logging.Logger instance with Fail2Ban logger name convention """ diff --git a/fail2ban/server/database.py b/fail2ban/server/database.py index 26e0223d..90a48d8d 100644 --- a/fail2ban/server/database.py +++ b/fail2ban/server/database.py @@ -51,11 +51,8 @@ if sys.version_info >= (3,): # pragma: 2.x no cover x = json.dumps(x, ensure_ascii=False, default=_json_default).encode( PREFER_ENC, 'replace') except Exception as e: - # adapter handler should be exception-safe, so avoid possible errors in log-handlers (concat, str. conversion, etc) - try: - logSys.error('json dumps failed: %r', e, exc_info=logSys.getEffectiveLevel() <= 4) - except: # pragma: no cover - pass + # adapter handler should be exception-safe + logSys.error('json dumps failed: %r', e, exc_info=logSys.getEffectiveLevel() <= 4) x = '{}' return x @@ -63,11 +60,8 @@ if sys.version_info >= (3,): # pragma: 2.x no cover try: x = json.loads(x.decode(PREFER_ENC, 'replace')) except Exception as e: - # converter handler should be exception-safe, so avoid possible errors in log-handlers (concat, str. conversion, etc) - try: - logSys.error('json loads failed: %r', e, exc_info=logSys.getEffectiveLevel() <= 4) - except: # pragma: no cover - pass + # converter handler should be exception-safe + logSys.error('json loads failed: %r', e, exc_info=logSys.getEffectiveLevel() <= 4) x = {} return x else: # pragma: 3.x no cover @@ -87,11 +81,8 @@ else: # pragma: 3.x no cover try: x = json.dumps(_normalize(x), ensure_ascii=False, default=_json_default) except Exception as e: - # adapter handler should be exception-safe, so avoid possible errors in log-handlers (concat, str. conversion, etc) - try: - logSys.error('json dumps failed: %r', e, exc_info=logSys.getEffectiveLevel() <= 4) - except: # pragma: no cover - pass + # adapter handler should be exception-safe + logSys.error('json dumps failed: %r', e, exc_info=logSys.getEffectiveLevel() <= 4) x = '{}' return x @@ -99,11 +90,8 @@ else: # pragma: 3.x no cover try: x = json.loads(x.decode(PREFER_ENC, 'replace')) except Exception as e: - # converter handler should be exception-safe, so avoid possible errors in log-handlers (concat, str. conversion, etc) - try: - logSys.error('json loads failed: %r', e, exc_info=logSys.getEffectiveLevel() <= 4) - except: # pragma: no cover - pass + # converter handler should be exception-safe + logSys.error('json loads failed: %r', e, exc_info=logSys.getEffectiveLevel() <= 4) x = {} return x diff --git a/fail2ban/tests/misctestcase.py b/fail2ban/tests/misctestcase.py index 707b6423..1e75fb95 100644 --- a/fail2ban/tests/misctestcase.py +++ b/fail2ban/tests/misctestcase.py @@ -201,6 +201,48 @@ class TestsUtilsTest(LogCaptureTestCase): uni_string('test\xcf') uni_string(u'test\xcf') + def testSafeLogging(self): + # logging should be exception-safe, to avoid possible errors (concat, str. conversion, representation failures, etc) + logSys = DefLogSys + class Test: + def __init__(self, err=1): + self.err = err + def __repr__(self): + if self.err: + raise Exception('no represenation for test!') + else: + return u'conv-error (\xf2\xf0\xe5\xf2\xe8\xe9), unterminated utf \xcf' + test = Test() + logSys.log(logging.NOTICE, "test 1a: %r", test) + self.assertLogged("Traceback", "no represenation for test!") + self.pruneLog() + logSys.notice("test 1b: %r", test) + self.assertLogged("Traceback", "no represenation for test!") + + self.pruneLog('[phase 2] test error conversion by encoding %s' % sys.getdefaultencoding()) + test = Test(0) + # this may produce coversion error on ascii default encoding: + #str(test) + logSys.log(logging.NOTICE, "test 2a: %r, %s", test, test) + self.assertLogged("test 2a", "Error by logging handler", all=False) + logSys.notice("test 2b: %r, %s", test, test) + self.assertLogged("test 2b", "Error by logging handler", all=False) + + self.pruneLog('[phase 3] test unexpected error in handler') + class _ErrorHandler(logging.Handler): + def handle(self, record): + raise Exception('error in handler test!') + _org_handler = logSys.handlers + try: + logSys.handlers = list(logSys.handlers) + logSys.handlers += [_ErrorHandler()] + logSys.log(logging.NOTICE, "test 3a") + logSys.notice("test 3b") + finally: + logSys.handlers = _org_handler + # we should reach this line without errors! + self.pruneLog('OK') + def testTraceBack(self): # pretty much just a smoke test since tests runners swallow all the detail diff --git a/fail2ban/tests/utils.py b/fail2ban/tests/utils.py index 4a243cbe..55617874 100644 --- a/fail2ban/tests/utils.py +++ b/fail2ban/tests/utils.py @@ -667,11 +667,14 @@ class LogCaptureTestCase(unittest.TestCase): self._strm.truncate(0) def __write(self, record): - msg = record.getMessage() + '\n' try: - self._strm.write(msg) - except UnicodeEncodeError: # pragma: no cover - normally unreachable now - self._strm.write(msg.encode('UTF-8', 'replace')) + msg = record.getMessage() + '\n' + try: + self._strm.write(msg) + except UnicodeEncodeError: # pragma: no cover - normally unreachable now + self._strm.write(msg.encode('UTF-8', 'replace')) + except Exception as e: # pragma: no cover - normally unreachable + self._strm.write('Error by logging handler: %r' % e) def getvalue(self): """Return current buffer as whole string.""" From 73e89df9129e4539ad3a311b2d65991c66fc138d Mon Sep 17 00:00:00 2001 From: sebres Date: Thu, 5 Jul 2018 23:04:38 +0200 Subject: [PATCH 5/6] amend to bcf557990e15922aff22485cc86ddd2fcf41b796: wrong logging syntax will not throw an error anymore (logged now, as logging is safe) --- fail2ban/tests/misctestcase.py | 11 ++++------- 1 file changed, 4 insertions(+), 7 deletions(-) diff --git a/fail2ban/tests/misctestcase.py b/fail2ban/tests/misctestcase.py index 1e75fb95..cd27ad92 100644 --- a/fail2ban/tests/misctestcase.py +++ b/fail2ban/tests/misctestcase.py @@ -416,13 +416,10 @@ class TestsUtilsTest(LogCaptureTestCase): def testLazyLogging(self): logSys = DefLogSys - if unittest.F2B.log_lazy: - # wrong logging syntax will throw an error lazy (on demand): - logSys.debug('test', 1, 2, 3) - self.assertRaisesRegexp(Exception, 'not all arguments converted', lambda: self.assertNotLogged('test')) - else: # pragma: no cover - # wrong logging syntax will throw an error directly: - self.assertRaisesRegexp(Exception, 'not all arguments converted', lambda: logSys.debug('test', 1, 2, 3)) + logSys.debug('lazy logging: %r', unittest.F2B.log_lazy) + # wrong logging syntax will don't throw an error anymore (logged now): + logSys.notice('test', 1, 2, 3) + self.assertLogged('not all arguments converted') class MyTimeTest(unittest.TestCase): From d0945120bf0a1c0ac6af0405569de2cfaca4b133 Mon Sep 17 00:00:00 2001 From: sebres Date: Fri, 6 Jul 2018 11:41:05 +0200 Subject: [PATCH 6/6] ChangeLog --- ChangeLog | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/ChangeLog b/ChangeLog index fc046c95..fefa7d5c 100644 --- a/ChangeLog +++ b/ChangeLog @@ -38,6 +38,13 @@ ver. 0.10.4-dev-1 (20??/??/??) - development edition * `filter.d/dovecot.conf`: failregex enhancement to catch sql password mismatch errors (gh-2153); * `action.d/hostsdeny.conf`: fix parameter in config (dynamic parameters stating with '_' are protected and don't allowed in command-actions), see gh-2114; +* decoding stability fix by wrong encoded characters like utf-8 surrogate pairs, etc (gh-2171): + - fail2ban running in the preferred encoding now (as default encoding also within python 2.x), mostly + `UTF-8` in opposite to `ascii` previously, so minimizes influence of implicit conversions errors; + - actions: avoid possible conversion errors on wrong-chars by replace tags; + - database: improve adapter/converter handlers working on invalid characters in sense of json and/or sqlite-database; + additionally both are exception-safe now, so avoid possible locking of database (closes gh-2137); + - logging in fail2ban is process-wide exception-safe now. ### New Features