assertLogged extended with parameter wait (to wait up to specified timeout, before we throw assert exception) + test cases rewritten using that

pull/1557/head
sebres 2016-09-09 17:50:25 +02:00
parent a20f325f80
commit e0347bb3a0
2 changed files with 49 additions and 46 deletions

View File

@ -737,11 +737,9 @@ class Fail2banServerTest(Fail2banClientServerBase):
if DefLogSys.level < logging.DEBUG: # if HEAVYDEBUG if DefLogSys.level < logging.DEBUG: # if HEAVYDEBUG
_out_file(test1log) _out_file(test1log)
self.execSuccess(startparams, "reload") self.execSuccess(startparams, "reload")
self.assertTrue( self.assertLogged(
Utils.wait_for(lambda: \ "Reload finished.",
self._is_logged("Reload finished.") and "1 ticket(s) in 'test-jail1", all=True, wait=MID_WAITTIME)
self._is_logged("1 ticket(s) in 'test-jail1")
, MID_WAITTIME))
self.assertLogged("Added logfile: %r" % test1log) self.assertLogged("Added logfile: %r" % test1log)
self.assertLogged("[test-jail1] Ban 192.0.2.1") self.assertLogged("[test-jail1] Ban 192.0.2.1")
# test actions started: # test actions started:
@ -757,8 +755,7 @@ class Fail2banServerTest(Fail2banClientServerBase):
if DefLogSys.level < logging.DEBUG: # if HEAVYDEBUG if DefLogSys.level < logging.DEBUG: # if HEAVYDEBUG
_out_file(test1log) _out_file(test1log)
self.execSuccess(startparams, "reload") self.execSuccess(startparams, "reload")
self.assertTrue( self.assertLogged("Reload finished.", all=True, wait=MID_WAITTIME)
Utils.wait_for(lambda: self._is_logged("Reload finished."), MID_WAITTIME))
# test not unbanned / banned again: # test not unbanned / banned again:
self.assertNotLogged( self.assertNotLogged(
"[test-jail1] Unban 192.0.2.1", "[test-jail1] Unban 192.0.2.1",
@ -784,8 +781,7 @@ class Fail2banServerTest(Fail2banClientServerBase):
reload=" echo '[<name>] %s: reloaded.'" % "test-action1", reload=" echo '[<name>] %s: reloaded.'" % "test-action1",
stop= " echo '[<name>] %s: stopped.'" % "test-action1") stop= " echo '[<name>] %s: stopped.'" % "test-action1")
self.execSuccess(startparams, "reload") self.execSuccess(startparams, "reload")
self.assertTrue( self.assertLogged("Reload finished.", all=True, wait=MID_WAITTIME)
Utils.wait_for(lambda: self._is_logged("Reload finished."), MID_WAITTIME))
# test not unbanned / banned again: # test not unbanned / banned again:
self.assertNotLogged( self.assertNotLogged(
"[test-jail1] Unban 192.0.2.1", "[test-jail1] Unban 192.0.2.1",
@ -821,11 +817,9 @@ class Fail2banServerTest(Fail2banClientServerBase):
if DefLogSys.level < logging.DEBUG: # if HEAVYDEBUG if DefLogSys.level < logging.DEBUG: # if HEAVYDEBUG
_out_file(test2log) _out_file(test2log)
# test all will be found in jail1 and one in jail2: # test all will be found in jail1 and one in jail2:
self.assertTrue( self.assertLogged(
Utils.wait_for(lambda: \ "2 ticket(s) in 'test-jail2",
self._is_logged("2 ticket(s) in 'test-jail2") and "5 ticket(s) in 'test-jail1", all=True, wait=MID_WAITTIME)
self._is_logged("5 ticket(s) in 'test-jail1")
, MID_WAITTIME))
self.assertLogged( self.assertLogged(
"[test-jail1] Ban 192.0.2.2", "[test-jail1] Ban 192.0.2.2",
"[test-jail1] Ban 192.0.2.3", "[test-jail1] Ban 192.0.2.3",
@ -848,12 +842,10 @@ class Fail2banServerTest(Fail2banClientServerBase):
self.pruneLog("[test-phase 2c]") self.pruneLog("[test-phase 2c]")
self.execSuccess(startparams, self.execSuccess(startparams,
"restart", "test-jail2") "restart", "test-jail2")
self.assertTrue( self.assertLogged(
Utils.wait_for(lambda: \ "Reload finished.",
self._is_logged("Reload finished.") and "Restore Ban",
self._is_logged("Restore Ban") and "2 ticket(s) in 'test-jail2", all=True, wait=MID_WAITTIME)
self._is_logged("2 ticket(s) in 'test-jail2")
, MID_WAITTIME))
# stop/start and unban/restore ban: # stop/start and unban/restore ban:
self.assertLogged( self.assertLogged(
"Jail 'test-jail2' stopped", "Jail 'test-jail2' stopped",
@ -868,11 +860,9 @@ class Fail2banServerTest(Fail2banClientServerBase):
self.pruneLog("[test-phase 2d]") self.pruneLog("[test-phase 2d]")
self.execSuccess(startparams, self.execSuccess(startparams,
"restart", "--unban", "test-jail2") "restart", "--unban", "test-jail2")
self.assertTrue( self.assertLogged(
Utils.wait_for(lambda: \ "Reload finished.",
self._is_logged("Reload finished.") and "Jail 'test-jail2' started", all=True, wait=MID_WAITTIME)
self._is_logged("Jail 'test-jail2' started")
, MID_WAITTIME))
self.assertLogged( self.assertLogged(
"Jail 'test-jail2' stopped", "Jail 'test-jail2' stopped",
"Jail 'test-jail2' started", "Jail 'test-jail2' started",
@ -888,8 +878,8 @@ class Fail2banServerTest(Fail2banClientServerBase):
# reload jail1 without restart (without ban/unban): # reload jail1 without restart (without ban/unban):
self.pruneLog("[test-phase 3]") self.pruneLog("[test-phase 3]")
self.execSuccess(startparams, "reload", "test-jail1") self.execSuccess(startparams, "reload", "test-jail1")
self.assertTrue( self.assertLogged(
Utils.wait_for(lambda: self._is_logged("Reload finished."), MID_WAITTIME)) "Reload finished.", all=True, wait=MID_WAITTIME)
self.assertLogged( self.assertLogged(
"Reload jail 'test-jail1'", "Reload jail 'test-jail1'",
"Jail 'test-jail1' reloaded", all=True) "Jail 'test-jail1' reloaded", all=True)
@ -903,8 +893,7 @@ class Fail2banServerTest(Fail2banClientServerBase):
self.pruneLog("[test-phase 4]") self.pruneLog("[test-phase 4]")
_write_jail_cfg(enabled=[1]) _write_jail_cfg(enabled=[1])
self.execSuccess(startparams, "reload") self.execSuccess(startparams, "reload")
self.assertTrue( self.assertLogged("Reload finished.", all=True, wait=MID_WAITTIME)
Utils.wait_for(lambda: self._is_logged("Reload finished."), MID_WAITTIME))
# test both jails should be reloaded: # test both jails should be reloaded:
self.assertLogged( self.assertLogged(
"Reload jail 'test-jail1'") "Reload jail 'test-jail1'")
@ -926,11 +915,9 @@ class Fail2banServerTest(Fail2banClientServerBase):
)) ))
if DefLogSys.level < logging.DEBUG: # if HEAVYDEBUG if DefLogSys.level < logging.DEBUG: # if HEAVYDEBUG
_out_file(test1log) _out_file(test1log)
self.assertTrue( self.assertLogged(
Utils.wait_for(lambda: \ "6 ticket(s) in 'test-jail1",
self._is_logged("6 ticket(s) in 'test-jail1") and "[test-jail1] 192.0.2.1 already banned", all=True, wait=MID_WAITTIME)
self._is_logged("[test-jail1] 192.0.2.1 already banned")
, MID_WAITTIME))
# test "failure" regexp still available: # test "failure" regexp still available:
self.assertLogged( self.assertLogged(
"[test-jail1] Found 192.0.2.1", "[test-jail1] Found 192.0.2.1",
@ -953,8 +940,7 @@ class Fail2banServerTest(Fail2banClientServerBase):
self.pruneLog("[test-phase 7]") self.pruneLog("[test-phase 7]")
self.execSuccess(startparams, self.execSuccess(startparams,
"reload", "--unban") "reload", "--unban")
self.assertTrue( self.assertLogged("Reload finished.", all=True, wait=MID_WAITTIME)
Utils.wait_for(lambda: self._is_logged("Reload finished."), MID_WAITTIME))
# reloads unbanned all: # reloads unbanned all:
self.assertLogged( self.assertLogged(
"Jail 'test-jail1' reloaded", "Jail 'test-jail1' reloaded",

View File

@ -589,8 +589,21 @@ class LogCaptureTestCase(unittest.TestCase):
logSys.handlers = self._old_handlers logSys.handlers = self._old_handlers
logSys.level = self._old_level logSys.level = self._old_level
def _is_logged(self, s): def _is_logged(self, *s, **kwargs):
return s in self._log.getvalue() logged = self._log.getvalue()
if not kwargs.get('all', False):
# at least one entry should be found:
for s_ in s:
if s_ in logged:
return True
if True: # pragma: no cover
return False
else:
# each entry should be found:
for s_ in s:
if s_ not in logged: # pragma: no cover
return False
return True
def assertLogged(self, *s, **kwargs): def assertLogged(self, *s, **kwargs):
"""Assert that one of the strings was logged """Assert that one of the strings was logged
@ -604,19 +617,23 @@ class LogCaptureTestCase(unittest.TestCase):
Test should succeed if string (or any of the listed) is present in the log Test should succeed if string (or any of the listed) is present in the log
all : boolean (default False) if True should fail if any of s not logged all : boolean (default False) if True should fail if any of s not logged
""" """
logged = self._log.getvalue() wait = kwargs.get('wait', None)
if wait:
res = Utils.wait_for(lambda: self._is_logged(*s, **kwargs), wait)
else:
res = self._is_logged(*s, **kwargs)
if not kwargs.get('all', False): if not kwargs.get('all', False):
# at least one entry should be found: # at least one entry should be found:
for s_ in s: if not res: # pragma: no cover
if s_ in logged: logged = self._log.getvalue()
return
if True: # pragma: no cover
self.fail("None among %r was found in the log: ===\n%s===" % (s, logged)) self.fail("None among %r was found in the log: ===\n%s===" % (s, logged))
else: else:
# each entry should be found: # each entry should be found:
for s_ in s: if not res: # pragma: no cover
if s_ not in logged: # pragma: no cover logged = self._log.getvalue()
self.fail("%r was not found in the log: ===\n%s===" % (s_, logged)) for s_ in s:
if s_ not in logged:
self.fail("%r was not found in the log: ===\n%s===" % (s_, logged))
def assertNotLogged(self, *s, **kwargs): def assertNotLogged(self, *s, **kwargs):
"""Assert that strings were not logged """Assert that strings were not logged