introduced new flag "banned" as property, used to recognize the ticket was really banned;

get/set restored flag functions rewritten to property "restored" similar to "banned";
several code optimizations and tests extensions;

6 files changed, 96 insertions, 30 deletions

diff --git a/fail2ban/server/actions.py b/fail2ban/server/actions.py
index 5ac7b9a9..bc8684b5 100644
--- a/fail2ban/server/actions.py
+++ b/fail2ban/server/actions.py
@@ -359,9 +359,10 @@ class Actions(JailThread, Mapping):
 				aInfo["ipjailmatches"]  = lambda: "\n".join(mi4ip().getMatches())
 				aInfo["ipfailures"]     = lambda: mi4ip(True).getAttempt()
 				aInfo["ipjailfailures"] = lambda: mi4ip().getAttempt()
-			if self.__banManager.addBanTicket(bTicket):
+			reason = {}
+			if self.__banManager.addBanTicket(bTicket, reason=reason):
 				cnt += 1
-				logSys.notice("[%s] %sBan %s", self._jail.name, ('' if not bTicket.getRestored() else 'Restore '), ip)
+				logSys.notice("[%s] %sBan %s", self._jail.name, ('' if not bTicket.restored else 'Restore '), ip)
 				for name, action in self._actions.iteritems():
 					try:
 						action.ban(aInfo.copy())
@@ -371,8 +372,22 @@ class Actions(JailThread, Mapping):
 							"info '%r': %s",
 							self._jail.name, name, aInfo, e,
 							exc_info=logSys.getEffectiveLevel()<=logging.DEBUG)
+				# after all actions are processed set banned flag:
+				bTicket.banned = True
 			else:
-				logSys.notice("[%s] %s already banned", self._jail.name, ip)
+				bTicket = reason['ticket']
+				# if already banned (otherwise still process some action)
+				if bTicket.banned:
+					# compare time of failure occurrence with time ticket was really banned:
+					diftm = ticket.getTime() - bTicket.getTime()
+					# log already banned with following level:
+					#   DEBUG   - before 3 seconds - certain interval for it, because of possible latency by recognizing in backends, etc.
+					#   NOTICE  - before 60 seconds - may still occurre if action are slow, or very high load in backend,
+					#   WARNING - after 60 seconds - very long time, something may be wrong
+					ll = logging.DEBUG   if diftm < 3 \
+					else logging.NOTICE  if diftm < 60 \
+					else logging.WARNING
+					logSys.log(ll, "[%s] %s already banned", self._jail.name, ip)
 		if cnt:
 			logSys.debug("Banned %s / %s, %s ticket(s) in %r", cnt, 
 				self.__banManager.getBanTotal(), self.__banManager.size(), self._jail.name)
diff --git a/fail2ban/server/banmanager.py b/fail2ban/server/banmanager.py
index 41e202ef..6da5366c 100644
--- a/fail2ban/server/banmanager.py
+++ b/fail2ban/server/banmanager.py
@@ -256,29 +256,30 @@ class BanManager:
 	# @param ticket the ticket
 	# @return True if the IP address is not in the ban list
 	
-	def addBanTicket(self, ticket):
+	def addBanTicket(self, ticket, reason={}):
+		eob = ticket.getEndOfBanTime(self.__banTime)
 		with self.__lock:
 			# check already banned
 			fid = ticket.getID()
 			oldticket = self.__banList.get(fid)
 			if oldticket:
-				# if already permanent
-				btold, told = oldticket.getBanTime(self.__banTime), oldticket.getTime()
-				if btold == -1:
-					return False
-				# if given time is less than already banned time
-				btnew, tnew = ticket.getBanTime(self.__banTime), ticket.getTime()
-				if btnew != -1 and tnew + btnew <= told + btold:
-					return False
-				# we have longest ban - set new (increment) ban time
-				oldticket.setTime(tnew)
-				oldticket.setBanTime(btnew)
+				reason['ticket'] = oldticket
+				# if new time for end of ban is larger than already banned end-time:
+				if eob > oldticket.getEndOfBanTime(self.__banTime):
+					# we have longest ban - set new (increment) ban time
+					reason['prolong'] = 1
+					btm = ticket.getBanTime(self.__banTime)
+					# if not permanent:
+					if btm != -1:
+						diftm = ticket.getTime() - oldticket.getTime()
+						if diftm > 0:
+							btm += diftm
+					oldticket.setBanTime(btm)
 				return False
-			# not yet banned - add new
+			# not yet banned - add new one:
 			self.__banList[fid] = ticket
 			self.__banTotal += 1
 			# correct next unban time:
-			eob = ticket.getEndOfBanTime(self.__banTime)
 			if self.__nextUnbanTime > eob:
 				self.__nextUnbanTime = eob
 			return True
diff --git a/fail2ban/server/jail.py b/fail2ban/server/jail.py
index 7e05a025..e70eaddd 100644
--- a/fail2ban/server/jail.py
+++ b/fail2ban/server/jail.py
@@ -28,7 +28,7 @@ import Queue
 
 from .actions import Actions
 from ..client.jailreader import JailReader
-from ..helpers import getLogger
+from ..helpers import getLogger, MyTime
 
 # Gets the instance of the logger.
 logSys = getLogger(__name__)
@@ -194,7 +194,7 @@ class Jail(object):
 		Used by filter to add a failure for banning.
 		"""
 		self.__queue.put(ticket)
-		if not ticket.getRestored() and self.database is not None:
+		if not ticket.restored and self.database is not None:
 			self.database.addBan(self, ticket)
 
 	def getFailTicket(self):
@@ -203,7 +203,8 @@ class Jail(object):
 		Used by actions to get a failure for banning.
 		"""
 		try:
-			return self.__queue.get(False)
+			ticket = self.__queue.get(False)
+			return ticket
 		except Queue.Empty:
 			return False
 
@@ -217,7 +218,17 @@ class Jail(object):
 					#logSys.debug('restored ticket: %s', ticket)
 					if not self.filter.inIgnoreIPList(ticket.getIP(), log_ignore=True):
 						# mark ticked was restored from database - does not put it again into db:
-						ticket.setRestored(True)
+						ticket.restored = True
+						# correct start time / ban time (by the same end of ban):
+						btm = ticket.getBanTime(forbantime)
+						diftm = MyTime.time() - ticket.getTime()
+						if btm != -1 and diftm > 0:
+							btm -= diftm
+						# ignore obsolete tickets:
+						if btm != -1 and btm <= 0:
+							continue
+						ticket.setTime(MyTime.time())
+						ticket.setBanTime(btm)
 						self.putFailTicket(ticket)
 		except Exception as e: # pragma: no cover
 			logSys.error('%s', e, exc_info=logSys.getEffectiveLevel()<=logging.DEBUG)
diff --git a/fail2ban/server/ticket.py b/fail2ban/server/ticket.py
index 8ff6a780..2f9a88ed 100644
--- a/fail2ban/server/ticket.py
+++ b/fail2ban/server/ticket.py
@@ -34,9 +34,10 @@ from .mytime import MyTime
 logSys = getLogger(__name__)
 
 
-class Ticket:
+class Ticket(object):
 	
 	RESTORED = 0x01
+	BANNED   = 0x08
 
 	def __init__(self, ip=None, time=None, matches=None, data={}, ticket=None):
 		"""Ticket constructor
@@ -135,14 +136,25 @@ class Ticket:
 	def getMatches(self):
 		return self._data.get('matches', [])
 
-	def setRestored(self, value):
+	@property
+	def restored(self):
+		return self._flags & Ticket.RESTORED
+	@restored.setter
+	def restored(self, value):
 		if value:
-			self._flags = Ticket.RESTORED
+			self._flags |= Ticket.RESTORED
 		else:
 			self._flags &= ~(Ticket.RESTORED)
 	
-	def getRestored(self):
-		return self._flags & Ticket.RESTORED
+	@property
+	def banned(self):
+		return self._flags & Ticket.BANNED
+	@banned.setter
+	def banned(self, value):
+		if value:
+			self._flags |= Ticket.BANNED
+		else:
+			self._flags &= ~(Ticket.BANNED)
 
 	def setData(self, *args, **argv):
 		# if overwrite - set data and filter None values:
diff --git a/fail2ban/tests/banmanagertestcase.py b/fail2ban/tests/banmanagertestcase.py
index c9f41c6c..4a86102c 100644
--- a/fail2ban/tests/banmanagertestcase.py
+++ b/fail2ban/tests/banmanagertestcase.py
@@ -53,11 +53,15 @@ class AddFailure(unittest.TestCase):
 		self.assertEqual(self.__banManager.size(), 1)
 
 	def testAddDuplicateWithTime(self):
+		defBanTime = self.__banManager.getBanTime()
+		prevEndOfBanTime = 0
 		# add again a duplicate :
-		#   1) with newer start time and the same ban time
+		#   0) with same start time and the same (default) ban time
+		#   1) with newer start time and the same (default) ban time
 		#   2) with same start time and longer ban time
     #   3) with permanent ban time (-1)
 		for tnew, btnew in (
+			(1167605999.0,       None),
 			(1167605999.0 + 100, None),
 			(1167605999.0,       24*60*60),
 			(1167605999.0,       -1),
@@ -71,9 +75,14 @@ class AddFailure(unittest.TestCase):
 			self.assertEqual(self.__banManager.size(), 1)
 			# pop ticket and check it was prolonged :
 			banticket = self.__banManager.getTicketByID(ticket2.getID())
-			self.assertEqual(banticket.getTime(), ticket2.getTime())
-			self.assertEqual(banticket.getTime(), ticket2.getTime())
-			self.assertEqual(banticket.getBanTime(), ticket2.getBanTime(self.__banManager.getBanTime()))
+			self.assertEqual(banticket.getEndOfBanTime(defBanTime), ticket2.getEndOfBanTime(defBanTime))
+			self.assertTrue(banticket.getEndOfBanTime(defBanTime) > prevEndOfBanTime)
+			prevEndOfBanTime = ticket1.getEndOfBanTime(defBanTime)
+			# but the start time should not be changed (+ 100 is ignored):
+			self.assertEqual(banticket.getTime(), 1167605999.0)
+			# if prolong to permanent, it should also have permanent ban time:
+			if btnew == -1:
+				self.assertEqual(banticket.getBanTime(defBanTime), -1)
 
 	def testInListOK(self):
 		self.assertTrue(self.__banManager.addBanTicket(self.__ticket))
diff --git a/fail2ban/tests/tickettestcase.py b/fail2ban/tests/tickettestcase.py
index 68a44bb5..277c2f28 100644
--- a/fail2ban/tests/tickettestcase.py
+++ b/fail2ban/tests/tickettestcase.py
@@ -108,6 +108,24 @@ class TicketTests(unittest.TestCase):
     self.assertEqual(ft2.getLastTime(), ft.getLastTime())
     self.assertEqual(ft2.getBanTime(), ft.getBanTime())
 
+  def testTicketFlags(self):
+    flags = ('restored', 'banned')
+    ticket = Ticket('test', 0)
+    trueflags = []
+    for v in (True, False, True):
+      for f in flags:
+        setattr(ticket, f, v)
+        if v:
+          trueflags.append(f)
+        else:
+          trueflags.remove(f)
+        for f2 in flags:
+          self.assertEqual(bool(getattr(ticket, f2)), f2 in trueflags)
+    ## inherite props from another tockets:
+    ticket = FailTicket(ticket=ticket)
+    for f2 in flags:
+      self.assertTrue(bool(getattr(ticket, f2)))
+
   def testTicketData(self):
     t = BanTicket('193.168.0.128', None, ['first', 'second'])
     # expand data (no overwrites, matches are available) :