fix sporadic bugs by starting of fast actions (execute fast sub processes), cherry picked from "f2b-perfom-prepare-716-cs":

- missing `popen` variable if not started;
- better readability for stdout and stderr in log (+ check log level before do logging);

fail2ban/server/utils.py

@@ -133,6 +133,7 @@ class Utils():
 			timeout_expr = lambda: time.time() - stime <= timeout
 		else:
 			timeout_expr = timeout
+		popen = None
 		try:
 			popen = subprocess.Popen(
 				realCmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE, shell=shell,
@@ -159,7 +160,10 @@ class Utils():
 				if retcode is None and not Utils.pid_exists(pgid):
 					retcode = signal.SIGKILL
 		except OSError as e:
-			logSys.error("%s -- failed with %s" % (realCmd, e))
+			stderr = "%s -- failed with %s" % (realCmd, e)
+			logSys.error(stderr)
+			if not popen:
+				return False if not output else (False, stdout, stderr, retcode)
 
 		std_level = retcode == 0 and logging.DEBUG or logging.ERROR
 		# if we need output (to return or to log it): 
@@ -172,8 +176,10 @@ class Utils():
 					stdout = popen.stdout.read()
 				except IOError as e:
 					logSys.error(" ... -- failed to read stdout %s", e)
-				if stdout is not None and stdout != '':
-					logSys.log(std_level, "%s -- stdout: %r", realCmd, stdout)
+				if stdout is not None and stdout != '' and std_level >= logSys.getEffectiveLevel():
+					logSys.log(std_level, "%s -- stdout:", realCmd)
+					for l in stdout.splitlines():
+						logSys.log(std_level, " -- stdout: %r", l)
 				popen.stdout.close()
 			if popen.stderr:
 				try:
@@ -182,8 +188,10 @@ class Utils():
 					stderr = popen.stderr.read()
 				except IOError as e:
 					logSys.error(" ... -- failed to read stderr %s", e)
-				if stderr is not None and stderr != '':
-					logSys.log(std_level, "%s -- stderr: %r", realCmd, stderr)
+				if stderr is not None and stderr != '' and std_level >= logSys.getEffectiveLevel():
+					logSys.log(std_level, "%s -- stderr:", realCmd)
+					for l in stderr.splitlines():
+						logSys.log(std_level, " -- stderr: %r", l)
 				popen.stderr.close()
 
 		success = False

fail2ban/tests/actiontestcase.py

@@ -271,11 +271,11 @@ class CommandActionTest(LogCaptureTestCase):
 
 	def testCaptureStdOutErr(self):
 		CommandAction.executeCmd('echo "How now brown cow"')
-		self.assertLogged("'How now brown cow\\n'")
+		self.assertLogged("stdout: 'How now brown cow'\n", "stdout: b'How now brown cow'\n")
 		CommandAction.executeCmd(
 			'echo "The rain in Spain stays mainly in the plain" 1>&2')
 		self.assertLogged(
-			"'The rain in Spain stays mainly in the plain\\n'")
+			"stderr: 'The rain in Spain stays mainly in the plain'\n", "stderr: b'The rain in Spain stays mainly in the plain'\n")
 
 	def testCallingMap(self):
 		mymap = CallingMap(callme=lambda: str(10), error=lambda: int('a'),