Merge branch '0.10' into 0.11

fail2ban/server/action.py

@@ -397,20 +397,20 @@ class CommandAction(ActionBase):
 		res = True
 		try:
 			# common (resp. ipv4):
-			startCmd = None
+			cmd = self._getOperation(tag, 'inet4')
 			if not family or 'inet4' in family:
-				startCmd = self._getOperation(tag, 'inet4')
+				if cmd:
-				if startCmd:
+					res &= self.executeCmd(cmd, self.timeout)
-					res &= self.executeCmd(startCmd, self.timeout)
+			# execute ipv6 operation if available (and not the same as ipv4):
-			# start ipv6 actions if available:
 			if allowed_ipv6 and (not family or 'inet6' in family):
-				startCmd6 = self._getOperation(tag, 'inet6')
+				cmd6 = self._getOperation(tag, 'inet6')
-				if startCmd6 and startCmd6 != startCmd:
+				if cmd6 and cmd6 != cmd: # - avoid double execution of same command
-					res &= self.executeCmd(startCmd6, self.timeout)
+					res &= self.executeCmd(cmd6, self.timeout)
 			if not res:
 				raise RuntimeError("Error %s action %s/%s" % (operation, self._jail, self._name,))
 		except ValueError as e:
 			raise RuntimeError("Error %s action %s/%s: %r" % (operation, self._jail, self._name, e))
+		return res
 
 	COND_FAMILIES = ('inet4', 'inet6')
 
@@ -418,28 +418,32 @@ class CommandAction(ActionBase):
 	def _startOnDemand(self):
 		"""Checks the action depends on family (conditional)"""
 		v = self._properties.get('actionstart_on_demand')
-		if v is None:
+		if v is not None:
-			v = False
+			return v
-			for n in self._properties:
+		# not set - auto-recognize (depending on conditional):
-				if CONDITIONAL_FAM_RE.match(n):
+		v = False
-					v = True
+		for n in self._properties:
-					break
+			if CONDITIONAL_FAM_RE.match(n):
+				v = True
+				break
 		self._properties['actionstart_on_demand'] = v
 		return v
 
-	def start(self, family=[]):
+	def start(self, family=None, forceStart=False):
 		"""Executes the "actionstart" command.
 
 		Replace the tags in the action command with actions properties
 		and executes the resulting command.
 		"""
-		if not family:
+		# check the action depends on family (conditional):
-			# check the action depends on family (conditional):
+		if self._startOnDemand:
-			if self._startOnDemand:
+			if not forceStart:
 				return True
 		elif self.__started.get(family): # pragma: no cover - normally unreachable
 			return True
-		return self._executeOperation('<actionstart>', 'starting', family=family)
+		ret = self._executeOperation('<actionstart>', 'starting', family=family)
+		self.__started[family] = ret
+		return ret
 
 	def ban(self, aInfo):
 		"""Executes the "actionban" command.
@@ -457,15 +461,7 @@ class CommandAction(ActionBase):
 		if self._startOnDemand:
 			family = aInfo.get('family')
 			if not self.__started.get(family):
-				self.start(family)
+				self.start(family, forceStart=True)
-				self.__started[family] = 1
-				# mark also another families as "started" (-1), if they are equal
-				# (on demand, but the same for ipv4 and ipv6):
-				cmd = self._getOperation('<actionstart>', family)
-				for f in CommandAction.COND_FAMILIES:
-					if f != family and not self.__started.get(f):
-						if cmd == self._getOperation('<actionstart>', f):
-							self.__started[f] = -1
 		# ban:
 		if not self._processCmd('<actionban>', aInfo):
 			raise RuntimeError("Error banning %(ip)s" % aInfo)
@@ -517,9 +513,7 @@ class CommandAction(ActionBase):
 		family = []
 		# collect started families, if started on demand (conditional):
 		if self._startOnDemand:
-			for f in CommandAction.COND_FAMILIES:
+			family = [f for (f,v) in self.__started.iteritems() if v]
-				if self.__started.get(f) == 1: # only real started:
-					family.append(f)
 			# if no started (on demand) actions:
 			if not family: return True
 		return self._executeOperation('<actionflush>', 'flushing', family=family)
@@ -533,12 +527,10 @@ class CommandAction(ActionBase):
 		family = []
 		# collect started families, if started on demand (conditional):
 		if self._startOnDemand:
-			for f in CommandAction.COND_FAMILIES:
+			family = [f for (f,v) in self.__started.iteritems() if v]
-				if self.__started.get(f) == 1: # only real started:
-					family.append(f)
-					self.__started[f] = 0
 			# if no started (on demand) actions:
 			if not family: return True
+		self.__started = {}
 		return self._executeOperation('<actionstop>', 'stopping', family=family)
 
 	def reload(self, **kwargs):

fail2ban/server/filtergamin.py

@@ -64,7 +64,7 @@ class FilterGamin(FileFilter):
 		logSys.debug("Created FilterGamin")
 
 	def callback(self, path, event):
-		logSys.debug("Got event: " + repr(event) + " for " + path)
+		logSys.log(4, "Got event: " + repr(event) + " for " + path)
 		if event in (gamin.GAMCreated, gamin.GAMChanged, gamin.GAMExists):
 			logSys.debug("File changed: " + path)
 			self.__modified = True

fail2ban/server/filterpoll.py

@@ -98,8 +98,8 @@ class FilterPoll(FileFilter):
 	def run(self):
 		while self.active:
 			try:
-				if logSys.getEffectiveLevel() <= 6:
+				if logSys.getEffectiveLevel() <= 4:
-					logSys.log(6, "Woke up idle=%s with %d files monitored",
+					logSys.log(4, "Woke up idle=%s with %d files monitored",
 							   self.idle, self.getLogCount())
 				if self.idle:
 					if not Utils.wait_for(lambda: not self.active or not self.idle, 
@@ -140,10 +140,10 @@ class FilterPoll(FileFilter):
 			logStats = os.stat(filename)
 			stats = logStats.st_mtime, logStats.st_ino, logStats.st_size
 			pstats = self.__prevStats.get(filename, (0))
-			if logSys.getEffectiveLevel() <= 5:
+			if logSys.getEffectiveLevel() <= 4:
 				# we do not want to waste time on strftime etc if not necessary
 				dt = logStats.st_mtime - pstats[0]
-				logSys.log(5, "Checking %s for being modified. Previous/current stats: %s / %s. dt: %s",
+				logSys.log(4, "Checking %s for being modified. Previous/current stats: %s / %s. dt: %s",
 				           filename, pstats, stats, dt)
 				# os.system("stat %s | grep Modify" % filename)
 			self.__file404Cnt[filename] = 0

fail2ban/server/filterpyinotify.py

@@ -87,7 +87,7 @@ class FilterPyinotify(FileFilter):
 		logSys.debug("Created FilterPyinotify")
 
 	def callback(self, event, origin=''):
-		logSys.log(7, "[%s] %sCallback for Event: %s", self.jailName, origin, event)
+		logSys.log(4, "[%s] %sCallback for Event: %s", self.jailName, origin, event)
 		path = event.pathname
 		# check watching of this path:
 		isWF = False

fail2ban/tests/fail2banclienttestcase.py

@@ -175,6 +175,7 @@ def _start_params(tmp, use_stock=False, use_stock_cfg=None,
 	cfg = pjoin(tmp, "config")
 	if db == 'auto':
 		db = pjoin(tmp, "f2b-db.sqlite3")
+	j_conf = 'jail.conf'
 	if use_stock and STOCK:
 		# copy config (sub-directories as alias):
 		def ig_dirs(dir, files):
@@ -196,6 +197,8 @@ def _start_params(tmp, use_stock=False, use_stock_cfg=None,
 			if r.match(line):
 				line = "backend = polling"
 			print(line)
+		# jails to local:
+		j_conf = 'jail.local' if jails else ''
 	else:
 		# just empty config directory without anything (only fail2ban.conf/jail.conf):
 		os.mkdir(cfg)
@@ -212,17 +215,23 @@ def _start_params(tmp, use_stock=False, use_stock_cfg=None,
 			"dbpurgeage = 1d",
 			"",
 		)
-		_write_file(pjoin(cfg, "jail.conf"), "w",
+	# write jails (local or conf):
+	if j_conf:
+		_write_file(pjoin(cfg, j_conf), "w",
 			*((
 				"[INCLUDES]", "",
 			  "[DEFAULT]", "tmp = " + tmp, "",
 			)+jails)
 		)
-		if unittest.F2B.log_level < logging.DEBUG: # pragma: no cover
-			_out_file(pjoin(cfg, "fail2ban.conf"))
-			_out_file(pjoin(cfg, "jail.conf"))
 	if f2b_local:
 		_write_file(pjoin(cfg, "fail2ban.local"), "w", *f2b_local)
+	if unittest.F2B.log_level < logging.DEBUG: # pragma: no cover
+		_out_file(pjoin(cfg, "fail2ban.conf"))
+		_out_file(pjoin(cfg, "jail.conf"))
+		if f2b_local:
+			_out_file(pjoin(cfg, "fail2ban.local"))
+		if j_conf and j_conf != "jail.conf":
+			_out_file(pjoin(cfg, j_conf))
 
 	# link stock actions and filters:
 	if use_stock_cfg and STOCK:
@@ -1340,6 +1349,121 @@ class Fail2banServerTest(Fail2banClientServerBase):
 		mp = _read_file(mpfn)
 		self.assertEqual(mp, '')
 
+	@unittest.F2B.skip_if_cfg_missing(filter="sendmail-auth")
+	@with_foreground_server_thread(startextra={
+		# create log-file (avoid "not found" errors):
+		'create_before_start': ('%(tmp)s/test.log',),
+		'use_stock': True,
+		# fail2ban.local:
+		'f2b_local': (
+			'[DEFAULT]',
+			'dbmaxmatches = 1'
+		),
+		# jail.local config:
+		'jails': (
+			# default:
+			'''test_action = dummy[actionstart_on_demand=1, init="start: %(__name__)s", target="%(tmp)s/test.txt",
+      actionban='<known/actionban>;
+        echo "<matches>"; printf "=====\\n%%b\\n=====\\n\\n" "<matches>" >> <target>']''',
+			# jail sendmail-auth:
+			'[sendmail-auth]',
+			'backend = polling',
+			'usedns = no',
+			'logpath = %(tmp)s/test.log',
+			'action = %(test_action)s',
+			'filter = sendmail-auth[logtype=short]',
+			'datepattern = ^Epoch',
+			'maxretry = 3',
+			'maxmatches = 2',
+			'enabled = true',
+			# jail sendmail-reject:
+			'[sendmail-reject]',
+			'backend = polling',
+			'usedns = no',
+			'logpath = %(tmp)s/test.log',
+			'action = %(test_action)s',
+			'filter = sendmail-reject[logtype=short]',
+			'datepattern = ^Epoch',
+			'maxretry = 3',
+			'enabled = true',
+		)
+	})
+	def testServerJails_Sendmail(self, tmp, startparams):
+		cfg = pjoin(tmp, "config")
+		lgfn = '%(tmp)s/test.log' % {'tmp': tmp}
+		tofn = '%(tmp)s/test.txt' % {'tmp': tmp}
+
+		smaut_msg = (
+			str(int(MyTime.time())) + ' smtp1 sm-mta[5133]: s1000000000001: [192.0.2.1]: possible SMTP attack: command=AUTH, count=1',
+			str(int(MyTime.time())) + ' smtp1 sm-mta[5133]: s1000000000002: [192.0.2.1]: possible SMTP attack: command=AUTH, count=2',
+			str(int(MyTime.time())) + ' smtp1 sm-mta[5133]: s1000000000003: [192.0.2.1]: possible SMTP attack: command=AUTH, count=3',
+		)
+		smrej_msg = (
+			str(int(MyTime.time())) + ' smtp1 sm-mta[21134]: s2000000000001: ruleset=check_rcpt, arg1=<123@example.com>, relay=xxx.dynamic.example.com [192.0.2.2], reject=550 5.7.1 <123@example.com>... Relaying denied. Proper authentication required.',
+			str(int(MyTime.time())) + ' smtp1 sm-mta[21134]: s2000000000002: ruleset=check_rcpt, arg1=<345@example.com>, relay=xxx.dynamic.example.com [192.0.2.2], reject=550 5.7.1 <345@example.com>... Relaying denied. Proper authentication required.',
+			str(int(MyTime.time())) + ' smtp1 sm-mta[21134]: s3000000000003: ruleset=check_rcpt, arg1=<567@example.com>, relay=xxx.dynamic.example.com [192.0.2.2], reject=550 5.7.1 <567@example.com>... Relaying denied. Proper authentication required.',
+		)
+
+		self.pruneLog("[test-phase sendmail-auth]")
+		# write log:
+		_write_file(lgfn, "w+", *smaut_msg)
+		# wait and check it caused banned (and dump in the test-file):
+		self.assertLogged(
+			"[sendmail-auth] Ban 192.0.2.1", "1 ticket(s) in 'sendmail-auth'", all=True, wait=MID_WAITTIME)
+		_out_file(tofn)
+		td = _read_file(tofn)
+		# check matches (maxmatches = 2, so only 2 & 3 available):
+		m = smaut_msg[0]
+		self.assertNotIn(m, td)
+		for m in smaut_msg[1:]:
+			self.assertIn(m, td)
+
+		self.pruneLog("[test-phase sendmail-reject]")
+		# write log:
+		_write_file(lgfn, "w+", *smrej_msg)
+		# wait and check it caused banned (and dump in the test-file):
+		self.assertLogged(
+			"[sendmail-reject] Ban 192.0.2.2", "1 ticket(s) in 'sendmail-reject'", all=True, wait=MID_WAITTIME)
+		_out_file(tofn)
+		td = _read_file(tofn)
+		# check matches (no maxmatches, so all matched messages are available):
+		for m in smrej_msg:
+			self.assertIn(m, td)
+
+		self.pruneLog("[test-phase restart sendmail-*]")
+		# restart jails (active ban-tickets should be restored):
+		self.execCmd(SUCCESS, startparams,
+			"reload", "--restart", "--all")
+		# wait a bit:
+		self.assertLogged(
+			"Reload finished.",
+			"[sendmail-auth] Restore Ban 192.0.2.1", "1 ticket(s) in 'sendmail-auth'", all=True, wait=MID_WAITTIME)
+		# check matches again - (dbmaxmatches = 1), so it should be only last match after restart:
+		td = _read_file(tofn)
+		m = smaut_msg[-1]
+		self.assertLogged(m)
+		self.assertIn(m, td)
+		for m in smaut_msg[0:-1]:
+			self.assertNotLogged(m)
+			self.assertNotIn(m, td)
+		# wait for restore of reject-jail:
+		self.assertLogged(
+			"[sendmail-reject] Restore Ban 192.0.2.2", "1 ticket(s) in 'sendmail-reject'", all=True, wait=MID_WAITTIME)
+		td = _read_file(tofn)
+		m = smrej_msg[-1]
+		self.assertLogged(m)
+		self.assertIn(m, td)
+		for m in smrej_msg[0:-1]:
+			self.assertNotLogged(m)
+			self.assertNotIn(m, td)
+
+		self.pruneLog("[test-phase stop server]")
+		# stop server and wait for end:
+		self.stopAndWaitForServerEnd(SUCCESS)
+
+		# just to debug actionstop:
+		self.assertFalse(exists(tofn))
+
 	@with_foreground_server_thread()
 	def testServerObserver(self, tmp, startparams):
 		cfg = pjoin(tmp, "config")