Merge pull request #1970 from sebres/fix-gh-1876

Fix logging to systemd-journal (gh-1876)

ChangeLog

@@ -39,6 +39,8 @@ ver. 0.10.2-dev-1 (2017/??/??) - development edition
   ports are enclosed in curly braces `{ }` in the `jail.local` etc. This may cause a double-brackets now.
 
 ### Fixes
+* Fixed logging to systemd-journal: new logtarget value SYSOUT can be used instead of STDOUT, to avoid 
+  write of the time-stamp, if logging to systemd-journal from foreground mode (gh-1876)
 * jail.conf: port `imap3` replaced with `imap` everywhere, since imap3 is not a standard port and old rarely 
   (if ever) used and can missing on some systems (e. g. debian stretch), see gh-1942.
 * config/paths-common.conf: added missing initial values (and small normalization in config/paths-*.conf)

config/fail2ban.conf

@@ -30,7 +30,7 @@ loglevel = INFO
 #         using logrotate -- also adjust or disable rotation in the
 #         corresponding configuration file
 #         (e.g. /etc/logrotate.d/fail2ban on Debian systems)
-# Values: [ STDOUT | STDERR | SYSLOG | FILE ]  Default: STDERR
+# Values: [ STDOUT | STDERR | SYSLOG | SYSOUT | FILE ]  Default: STDERR
 #
 logtarget = /var/log/fail2ban.log
 

fail2ban/client/fail2bancmdline.py

@@ -99,7 +99,7 @@ class Fail2banCmdLine():
 		output("    -s <FILE>               socket path")
 		output("    -p <FILE>               pidfile path")
 		output("    --loglevel <LEVEL>      logging level")
-		output("    --logtarget <FILE>|STDOUT|STDERR|SYSLOG")
+		output("    --logtarget <TARGET>    logging target, use file-name or stdout, stderr, syslog or sysout.")
 		output("    --syslogsocket auto|<FILE>")
 		output("    -d                      dump configuration. For debugging")
 		output("    --dp, --dump-pretty     dump the configuration using more human readable representation")

fail2ban/client/fail2banserver.py

@@ -210,6 +210,7 @@ class Fail2banServer(Fail2banCmdLine):
 					if server: # pragma: no cover
 						server.quit()
 					exit(-1)
+				if background:
 					logSys.debug('Starting server done')
 
 		except Exception as e:

fail2ban/helpers.py

@@ -143,7 +143,7 @@ def str2LogLevel(value):
 		raise ValueError("Invalid log level %r" % value)
 	return ll
 
-def getVerbosityFormat(verbosity, fmt=' %(message)s'):
+def getVerbosityFormat(verbosity, fmt=' %(message)s', addtime=True):
 	"""Custom log format for the verbose runs
 	"""
 	if verbosity > 1: # pragma: no cover
@@ -152,7 +152,9 @@ def getVerbosityFormat(verbosity, fmt=' %(message)s'):
 		if verbosity > 2:
 			fmt = ' +%(relativeCreated)5d %(thread)X %(name)-25.25s %(levelname)-5.5s' + fmt
 		else:
-			fmt = ' %(asctime)-15s %(thread)X %(levelname)-5.5s' + fmt
+			fmt = ' %(thread)X %(levelname)-5.5s' + fmt
+			if addtime:
+				fmt = ' %(asctime)-15s' + fmt
 	return fmt
 
 

fail2ban/server/server.py

@@ -27,7 +27,6 @@ __license__ = "GPL"
 import threading
 from threading import Lock, RLock
 import logging
-import logging.handlers
 import os
 import signal
 import stat
@@ -152,6 +151,23 @@ class Server:
 			self.__asyncServer.start(sock, force)
 		except AsyncServerException as e:
 			logSys.error("Could not start server: %s", e)
+
+		logSys.info("Shutdown in progress...")
+
+		# Restore default signal handlers:
+		if _thread_name() == '_MainThread':
+			for s, sh in self.__prev_signals.iteritems():
+				signal.signal(s, sh)
+
+		# Now stop all the jails
+		self.stopAllJail()
+
+		# Explicit close database (server can leave in a thread, 
+		# so delayed GC can prevent commiting changes)
+		if self.__db:
+			self.__db.close()
+			self.__db = None
+
 		# Removes the PID file.
 		try:
 			logSys.debug("Remove PID file %s", pidfile)
@@ -161,6 +177,8 @@ class Server:
 		logSys.info("Exiting Fail2ban")
 
 	def quit(self):
+		# Prevent to call quit twice:
+		self.quit = lambda: False
 		# Stop communication first because if jail's unban action
 		# tries to communicate via fail2ban-client we get a lockup
 		# among threads.  So the simplest resolution is to stop all
@@ -171,28 +189,6 @@ class Server:
 			self.__asyncServer.stop()
 			self.__asyncServer = None
 
-		# Now stop all the jails
-		self.stopAllJail()
-
-		# Explicit close database (server can leave in a thread, 
-		# so delayed GC can prevent commiting changes)
-		if self.__db:
-			self.__db.close()
-			self.__db = None
-
-		# Only now shutdown the logging.
-		if self.__logTarget is not None:
-			with self.__loggingLock:
-				logging.shutdown()
-
-		# Restore default signal handlers:
-		if _thread_name() == '_MainThread':
-			for s, sh in self.__prev_signals.iteritems():
-				signal.signal(s, sh)
-
-		# Prevent to call quit twice:
-		self.quit = lambda: False
-
 	def addJail(self, name, backend):
 		addflg = True
 		if self.__reload_state.get(name) and self.__jails.exists(name):
@@ -561,10 +557,8 @@ class Server:
 				self.__logTarget = target
 				return True
 			# set a format which is simpler for console use
-			fmt = "%(asctime)s %(name)-24s[%(process)d]: %(levelname)-7s %(message)s"
+			fmt = "%(name)-24s[%(process)d]: %(levelname)-7s %(message)s"
 			if systarget == "SYSLOG":
-				# Syslog daemons already add date to the message.
-				fmt = "%(name)s[%(process)d]: %(levelname)s %(message)s"
 				facility = logging.handlers.SysLogHandler.LOG_DAEMON
 				if self.__syslogSocket == "auto":
 					import platform
@@ -581,7 +575,7 @@ class Server:
 						"Syslog socket file: %s does not exists"
 						" or is not a socket" % self.__syslogSocket)
 					return False
-			elif systarget == "STDOUT":
+			elif systarget in ("STDOUT", "SYSOUT"):
 				hdlr = logging.StreamHandler(sys.stdout)
 			elif systarget == "STDERR":
 				hdlr = logging.StreamHandler(sys.stderr)
@@ -615,8 +609,14 @@ class Server:
 			if logger.getEffectiveLevel() <= logging.DEBUG: # pragma: no cover
 				if self.__verbose is None:
 					self.__verbose = logging.DEBUG - logger.getEffectiveLevel() + 1
+			# If handler don't already add date to the message:
+			addtime = systarget not in ("SYSLOG", "SYSOUT")
+			# verbose log-format:
 			if self.__verbose is not None and self.__verbose > 2: # pragma: no cover
-				fmt = getVerbosityFormat(self.__verbose-1)
+				fmt = getVerbosityFormat(self.__verbose-1,
+					addtime=addtime)
+			elif addtime:
+				fmt = "%(asctime)s " + fmt
 			# tell the handler to use this format
 			hdlr.setFormatter(logging.Formatter(fmt))
 			logger.addHandler(hdlr)

files/bash-completion

@@ -108,7 +108,7 @@ _fail2ban () {
                     ;;
                 logtarget)
                     if [[ "$cmd" == "set" ]];then
-                        COMPREPLY=( $( compgen -W "STDOUT STDERR SYSLOG" -- "$cur" ) )
+                        COMPREPLY=( $( compgen -W "STDOUT STDERR SYSLOG SYSOUT" -- "$cur" ) )
                         _filedir # And files
                     fi
                     return 0

files/fail2ban.service.in

@@ -8,8 +8,8 @@ PartOf=iptables.service firewalld.service ip6tables.service ipset.service
 Type=simple
 ExecStartPre=/bin/mkdir -p /var/run/fail2ban
 ExecStart=@BINDIR@/fail2ban-server -xf start
-# if should be logged in systemd journal, use following line or set logtarget to stdout in fail2ban.local
+# if should be logged in systemd journal, use following line or set logtarget to sysout in fail2ban.local
-# ExecStart=@BINDIR@/fail2ban-server -xf --logtarget=stdout start
+# ExecStart=@BINDIR@/fail2ban-server -xf --logtarget=sysout start
 ExecStop=@BINDIR@/fail2ban-client stop
 ExecReload=@BINDIR@/fail2ban-client reload
 PIDFile=/var/run/fail2ban/fail2ban.pid

man/fail2ban-client.1

@@ -21,8 +21,9 @@ pidfile path
 .TP
 \fB\-\-loglevel\fR <LEVEL>
 logging level
-.HP
+.TP
-\fB\-\-logtarget\fR <FILE>|STDOUT|STDERR|SYSLOG
+\fB\-\-logtarget\fR <TARGET>
+logging target, use file\-name or stdout, stderr, syslog or sysout.
 .HP
 \fB\-\-syslogsocket\fR auto|<FILE>
 .TP

man/fail2ban-server.1

@@ -21,8 +21,9 @@ pidfile path
 .TP
 \fB\-\-loglevel\fR <LEVEL>
 logging level
-.HP
+.TP
-\fB\-\-logtarget\fR <FILE>|STDOUT|STDERR|SYSLOG
+\fB\-\-logtarget\fR <TARGET>
+logging target, use file\-name or stdout, stderr, syslog or sysout.
 .HP
 \fB\-\-syslogsocket\fR auto|<FILE>
 .TP