ENH: Realign and harmonise log messages with getF2BLogger helper

ChangeLog

@@ -38,6 +38,8 @@ ver. 0.9.1 (2014/xx/xx) - better, faster, stronger
    * Fail2ban-regex - add print-all-matched option. Closes gh-652
    * Suppress fail2ban-client warnings for non-critical config options
    * Match non "Bye Bye" disconnect messages for sshd locked account regex
+   * Realign fail2ban log output with white space to improve readability. Does
+     not affect SYSLOG output.
 
 ver. 0.9.0 (2014/03/14) - beta
 ----------

bin/fail2ban-client

@@ -32,7 +32,7 @@ from fail2ban.client.configurator import Configurator
 from fail2ban.client.beautifier import Beautifier
 
 # Gets the instance of the logger.
-logSys = logging.getLogger("fail2ban.client")
+logSys = logging.getLogger("fail2ban")
 
 ##
 #

config/filter.d/recidive.conf

@@ -21,7 +21,7 @@ before = common.conf
 
 [Definition]
 
-_daemon = fail2ban\.server\.actions
+_daemon = fail2ban\.actions\s*
 
 # The name of the jail that this filter is used for. In jail.conf, name the 
 # jail using this filter 'recidive', or change this line!

fail2ban/client/actionreader.py

@@ -24,12 +24,13 @@ __author__ = "Cyril Jaquier"
 __copyright__ = "Copyright (c) 2004 Cyril Jaquier"
 __license__ = "GPL"
 
-import logging, os
+import os
 
 from .configreader import ConfigReader, DefinitionInitConfigReader
+from ..helpers import getF2BLogger
 
 # Gets the instance of the logger.
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 class ActionReader(DefinitionInitConfigReader):
 

fail2ban/client/beautifier.py

@@ -21,12 +21,11 @@ __author__ = "Cyril Jaquier, Yaroslav Halchenko"
 __copyright__ = "Copyright (c) 2004 Cyril Jaquier, 2013- Yaroslav Halchenko"
 __license__ = "GPL"
 
-import logging
-
 from ..exceptions import UnknownJailException, DuplicateJailException
+from ..helpers import getF2BLogger
 
 # Gets the instance of the logger.
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 ##
 # Beautify the output of the client.

fail2ban/client/configparserinc.py

@@ -24,7 +24,8 @@ __author__ = 'Yaroslav Halhenko'
 __copyright__ = 'Copyright (c) 2007 Yaroslav Halchenko'
 __license__ = 'GPL'
 
-import logging, os, sys
+import os, sys
+from ..helpers import getF2BLogger
 
 if sys.version_info >= (3,2): # pragma: no cover
 
@@ -60,7 +61,7 @@ else: # pragma: no cover
 	from ConfigParser import SafeConfigParser
 
 # Gets the instance of the logger.
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 __all__ = ['SafeConfigParserWithIncludes']
 

fail2ban/client/configreader.py

@@ -24,13 +24,14 @@ __author__ = "Cyril Jaquier"
 __copyright__ = "Copyright (c) 2004 Cyril Jaquier"
 __license__ = "GPL"
 
-import glob, logging, os
+import glob, os
 from ConfigParser import NoOptionError, NoSectionError
 
 from .configparserinc import SafeConfigParserWithIncludes
+from ..helpers import getF2BLogger
 
 # Gets the instance of the logger.
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 class ConfigReader(SafeConfigParserWithIncludes):
 

fail2ban/client/configurator.py

@@ -24,13 +24,12 @@ __author__ = "Cyril Jaquier"
 __copyright__ = "Copyright (c) 2004 Cyril Jaquier"
 __license__ = "GPL"
 
-import logging
-
 from .fail2banreader import Fail2banReader
 from .jailsreader import JailsReader
+from ..helpers import getF2BLogger
 
 # Gets the instance of the logger.
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 class Configurator:
 	

fail2ban/client/fail2banreader.py

@@ -24,12 +24,11 @@ __author__ = "Cyril Jaquier"
 __copyright__ = "Copyright (c) 2004 Cyril Jaquier"
 __license__ = "GPL"
 
-import logging
-
 from .configreader import ConfigReader
+from ..helpers import getF2BLogger
 
 # Gets the instance of the logger.
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 class Fail2banReader(ConfigReader):
 	

fail2ban/client/filterreader.py

@@ -24,13 +24,14 @@ __author__ = "Cyril Jaquier"
 __copyright__ = "Copyright (c) 2004 Cyril Jaquier"
 __license__ = "GPL"
 
-import logging, os, shlex
+import os, shlex
 
 from .configreader import ConfigReader, DefinitionInitConfigReader
 from ..server.action import CommandAction
+from ..helpers import getF2BLogger
 
 # Gets the instance of the logger.
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 class FilterReader(DefinitionInitConfigReader):
 

fail2ban/client/jailreader.py

@@ -24,15 +24,16 @@ __author__ = "Cyril Jaquier"
 __copyright__ = "Copyright (c) 2004 Cyril Jaquier"
 __license__ = "GPL"
 
-import logging, re, glob, os.path
+import re, glob, os.path
 import json
 
 from .configreader import ConfigReader
 from .filterreader import FilterReader
 from .actionreader import ActionReader
+from ..helpers import getF2BLogger
 
 # Gets the instance of the logger.
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 class JailReader(ConfigReader):
 	

fail2ban/client/jailsreader.py

@@ -24,13 +24,12 @@ __author__ = "Cyril Jaquier"
 __copyright__ = "Copyright (c) 2004 Cyril Jaquier"
 __license__ = "GPL"
 
-import logging
-
 from .configreader import ConfigReader
 from .jailreader import JailReader
+from ..helpers import getF2BLogger
 
 # Gets the instance of the logger.
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 class JailsReader(ConfigReader):
 

fail2ban/helpers.py

@@ -107,3 +107,8 @@ class FormatterWithTraceBack(logging.Formatter):
 	def format(self, record):
 		record.tbc = record.tb = self._tb()
 		return logging.Formatter.format(self, record)
+
+def getF2BLogger(name):
+	"""Get logging.Logger instance with Fail2Ban logger name convention
+	"""
+	return logging.getLogger("fail2ban.%s" % name.rpartition(".")[-1])

fail2ban/server/action.py

@@ -25,10 +25,11 @@ import logging, os, subprocess, time, signal, tempfile
 import threading, re
 from abc import ABCMeta
 from collections import MutableMapping
-#from subprocess import call
+
+from ..helpers import getF2BLogger
 
 # Gets the instance of the logger.
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 # Create a lock for running system commands
 _cmd_lock = threading.Lock()
@@ -136,7 +137,7 @@ class ActionBase(object):
 		self._jail = jail
 		self._name = name
 		self._logSys = logging.getLogger(
-			'%s.%s' % (__name__, self.__class__.__name__))
+			"fail2ban.%s" % self.__class__.__name__)
 
 	def start(self):
 		"""Executed when the jail/action is started.

fail2ban/server/actions.py

@@ -41,9 +41,10 @@ from .banmanager import BanManager
 from .jailthread import JailThread
 from .action import ActionBase, CommandAction, CallingMap
 from .mytime import MyTime
+from ..helpers import getF2BLogger
 
 # Gets the instance of the logger.
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 class Actions(JailThread, Mapping):
 	"""Handles jail actions.

fail2ban/server/asyncserver.py

@@ -25,12 +25,12 @@ __copyright__ = "Copyright (c) 2004 Cyril Jaquier"
 __license__ = "GPL"
 
 from pickle import dumps, loads, HIGHEST_PROTOCOL
-import asyncore, asynchat, socket, os, logging, sys, traceback, fcntl
+import asyncore, asynchat, socket, os, sys, traceback, fcntl
 
-from .. import helpers
+from ..helpers import getF2BLogger,formatExceptionInfo
 
 # Gets the instance of the logger.
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 if sys.version_info >= (3,):
 	# b"" causes SyntaxError in python <= 2.5, so below implements equivalent
@@ -81,7 +81,7 @@ class RequestHandler(asynchat.async_chat):
 		self.close_when_done()
 		
 	def handle_error(self):
-		e1, e2 = helpers.formatExceptionInfo()
+		e1, e2 = formatExceptionInfo()
 		logSys.error("Unexpected communication error: %s" % str(e2))
 		logSys.error(traceback.format_exc().splitlines())
 		self.close()

fail2ban/server/banmanager.py

@@ -24,14 +24,14 @@ __author__ = "Cyril Jaquier"
 __copyright__ = "Copyright (c) 2004 Cyril Jaquier"
 __license__ = "GPL"
 
-import logging
 from threading import Lock
 
 from .ticket import BanTicket
 from .mytime import MyTime
+from ..helpers import getF2BLogger
 
 # Gets the instance of the logger.
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 ##
 # Banning Manager.

fail2ban/server/database.py

@@ -21,7 +21,6 @@ __author__ = "Steven Hiscocks"
 __copyright__ = "Copyright (c) 2013 Steven Hiscocks"
 __license__ = "GPL"
 
-import logging
 import sys
 import shutil, time
 import sqlite3
@@ -32,9 +31,10 @@ from threading import Lock
 
 from .mytime import MyTime
 from .ticket import FailTicket
+from ..helpers import getF2BLogger
 
 # Gets the instance of the logger.
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 if sys.version_info >= (3,):
 	sqlite3.register_adapter(

fail2ban/server/datedetector.py

@@ -21,13 +21,13 @@ __author__ = "Cyril Jaquier and Fail2Ban Contributors"
 __copyright__ = "Copyright (c) 2004 Cyril Jaquier"
 __license__ = "GPL"
 
-import logging
 from threading import Lock
 
 from .datetemplate import DatePatternRegex, DateTai64n, DateEpoch
+from ..helpers import getF2BLogger
 
 # Gets the instance of the logger.
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 class DateDetector(object):
 	"""Manages one or more date templates to find a date within a log line.

fail2ban/server/datetemplate.py

@@ -25,12 +25,12 @@ __copyright__ = "Copyright (c) 2004 Cyril Jaquier"
 __license__ = "GPL"
 
 import re
-import logging
 from abc import abstractmethod
 
 from .strptime import reGroupDictStrptime, timeRE
+from ..helpers import getF2BLogger
 
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 
 class DateTemplate(object):

fail2ban/server/faildata.py

@@ -24,10 +24,10 @@ __author__ = "Cyril Jaquier"
 __copyright__ = "Copyright (c) 2004 Cyril Jaquier"
 __license__ = "GPL"
 
-import logging
+from ..helpers import getF2BLogger
 
 # Gets the instance of the logger.
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 class FailData:
 	

fail2ban/server/failmanager.py

@@ -29,9 +29,10 @@ import logging
 
 from .faildata import FailData
 from .ticket import FailTicket
+from ..helpers import getF2BLogger
 
 # Gets the instance of the logger.
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 class FailManager:
 	

fail2ban/server/filter.py

@@ -21,7 +21,7 @@ __author__ = "Cyril Jaquier and Fail2Ban Contributors"
 __copyright__ = "Copyright (c) 2004 Cyril Jaquier, 2011-2013 Yaroslav Halchenko"
 __license__ = "GPL"
 
-import logging, re, os, fcntl, sys, locale, codecs
+import re, os, fcntl, sys, locale, codecs
 
 from .failmanager import FailManagerEmpty, FailManager
 from .ticket import FailTicket
@@ -31,9 +31,10 @@ from .datetemplate import DatePatternRegex, DateEpoch, DateTai64n
 from .mytime import MyTime
 from .failregex import FailRegex, Regex, RegexException
 from .action import CommandAction
+from ..helpers import getF2BLogger
 
 # Gets the instance of the logger.
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 ##
 # Log reader class.

fail2ban/server/filtergamin.py

@@ -23,16 +23,17 @@ __author__ = "Cyril Jaquier, Yaroslav Halchenko"
 __copyright__ = "Copyright (c) 2004 Cyril Jaquier, 2012 Yaroslav Halchenko"
 __license__ = "GPL"
 
-import time, logging, fcntl
+import time, fcntl
 
 import gamin
 
 from .failmanager import FailManagerEmpty
 from .filter import FileFilter
 from .mytime import MyTime
+from ..helpers import getF2BLogger
 
 # Gets the instance of the logger.
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 ##
 # Log reader class.

fail2ban/server/filterpoll.py

@@ -24,14 +24,15 @@ __author__ = "Cyril Jaquier, Yaroslav Halchenko"
 __copyright__ = "Copyright (c) 2004 Cyril Jaquier; 2012 Yaroslav Halchenko"
 __license__ = "GPL"
 
-import time, logging, os
+import time, os
 
 from .failmanager import FailManagerEmpty
 from .filter import FileFilter
 from .mytime import MyTime
+from ..helpers import getF2BLogger
 
 # Gets the instance of the logger.
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 ##
 # Log reader class.

fail2ban/server/filterpyinotify.py

@@ -32,6 +32,7 @@ import pyinotify
 from .failmanager import FailManagerEmpty
 from .filter import FileFilter
 from .mytime import MyTime
+from ..helpers import getF2BLogger
 
 
 if not hasattr(pyinotify, '__version__') \
@@ -48,7 +49,7 @@ except Exception, e:
 					  % str(e))
 
 # Gets the instance of the logger.
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 ##
 # Log reader class.

fail2ban/server/filtersystemd.py

@@ -22,7 +22,7 @@ __author__ = "Steven Hiscocks"
 __copyright__ = "Copyright (c) 2013 Steven Hiscocks"
 __license__ = "GPL"
 
-import logging, datetime, time
+import datetime, time
 from distutils.version import LooseVersion
 
 from systemd import journal
@@ -32,10 +32,10 @@ if LooseVersion(getattr(journal, '__version__', "0")) < '204':
 from .failmanager import FailManagerEmpty
 from .filter import JournalFilter
 from .mytime import MyTime
-
+from ..helpers import getF2BLogger
 
 # Gets the instance of the logger.
-logSys = logging.getLogger("fail2ban.filter")
+logSys = getF2BLogger(__name__)
 
 ##
 # Journal reader class.

fail2ban/server/jail.py

@@ -26,9 +26,10 @@ __license__ = "GPL"
 import Queue, logging
 
 from .actions import Actions
+from ..helpers import getF2BLogger
 
 # Gets the instance of the logger.
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 class Jail:
 	"""Fail2Ban jail, which manages a filter and associated actions.

fail2ban/server/server.py

@@ -32,9 +32,10 @@ from .filter import FileFilter, JournalFilter
 from .transmitter import Transmitter
 from .asyncserver import AsyncServer, AsyncServerException
 from .. import version
+from ..helpers import getF2BLogger
 
 # Gets the instance of the logger.
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 try:
 	from .database import Fail2BanDb
@@ -335,7 +336,7 @@ class Server:
 	def setLogLevel(self, value):
 		try:
 			self.__loggingLock.acquire()
-			logging.getLogger(__name__).parent.parent.setLevel(
+			logging.getLogger("fail2ban").setLevel(
 				getattr(logging, value.upper()))
 		except AttributeError:
 			raise ValueError("Invalid log level")
@@ -367,7 +368,7 @@ class Server:
 		try:
 			self.__loggingLock.acquire()
 			# set a format which is simpler for console use
-			formatter = logging.Formatter("%(asctime)s %(name)-16s[%(process)d]: %(levelname)-7s %(message)s")
+			formatter = logging.Formatter("%(asctime)s %(name)-24s[%(process)d]: %(levelname)-7s %(message)s")
 			if target == "SYSLOG":
 				# Syslog daemons already add date to the message.
 				formatter = logging.Formatter("%(name)s[%(process)d]: %(levelname)s %(message)s")
@@ -388,7 +389,7 @@ class Server:
 					return False
 			# Removes previous handlers -- in reverse order since removeHandler
 			# alter the list in-place and that can confuses the iterable
-			logger = logging.getLogger(__name__).parent.parent
+			logger = logging.getLogger("fail2ban")
 			for handler in logger.handlers[::-1]:
 				# Remove the handler.
 				logger.removeHandler(handler)
@@ -425,7 +426,7 @@ class Server:
 	
 	def flushLogs(self):
 		if self.__logTarget not in ['STDERR', 'STDOUT', 'SYSLOG']:
-			for handler in logging.getLogger(__name__).parent.parent.handlers:
+			for handler in logging.getLogger("fail2ban").handlers:
 				try:
 					handler.doRollover()
 					logSys.info("rollover performed on %s" % self.__logTarget)
@@ -434,7 +435,7 @@ class Server:
 					logSys.info("flush performed on %s" % self.__logTarget)
 			return "rolled over"
 		else:
-			for handler in logging.getLogger(__name__).parent.parent.handlers:
+			for handler in logging.getLogger("fail2ban").handlers:
 				handler.flush()
 				logSys.info("flush performed on %s" % self.__logTarget)
 			return "flushed"

fail2ban/server/ticket.py

@@ -24,10 +24,10 @@ __author__ = "Cyril Jaquier"
 __copyright__ = "Copyright (c) 2004 Cyril Jaquier"
 __license__ = "GPL"
 
-import logging
+from ..helpers import getF2BLogger
 
 # Gets the instance of the logger.
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 class Ticket:
 	

fail2ban/server/transmitter.py

@@ -24,11 +24,13 @@ __author__ = "Cyril Jaquier"
 __copyright__ = "Copyright (c) 2004 Cyril Jaquier"
 __license__ = "GPL"
 
-import logging, time
+import time
 import json
 
+from ..helpers import getF2BLogger
+
 # Gets the instance of the logger.
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 class Transmitter:
 	

fail2ban/tests/files/logs/recidive

@@ -1,14 +1,14 @@
 # failJSON: { "time": "2006-02-13T15:52:30", "match": true , "host": "1.2.3.4" }
-2006-02-13 15:52:30,388 fail2ban.server.actions: NOTICE [sendmail] Ban 1.2.3.4
+2006-02-13 15:52:30,388 fail2ban.actions: NOTICE [sendmail] Ban 1.2.3.4
 # failJSON: { "time": "2006-02-13T15:52:30", "match": true , "host": "1.2.3.4", "desc": "Extended with [PID]" }
-2006-02-13 15:52:30,388 fail2ban.server.actions[123]: NOTICE [sendmail] Ban 1.2.3.4
+2006-02-13 15:52:30,388 fail2ban.actions[123]: NOTICE [sendmail] Ban 1.2.3.4
 # failJSON: { "match": false }
-2006-02-13 16:07:31,183 fail2ban.server.actions: NOTICE [sendmail] Unban 1.2.3.4
+2006-02-13 16:07:31,183 fail2ban.actions: NOTICE [sendmail] Unban 1.2.3.4
 # failJSON: { "match": false }
-2006-02-13 15:52:30,388 fail2ban.server.actions: NOTICE [recidive] Ban 1.2.3.4
+2006-02-13 15:52:30,388 fail2ban.actions: NOTICE [recidive] Ban 1.2.3.4
 # syslog example
 # failJSON: { "time": "2004-09-16T00:44:55", "match": true , "host": "10.0.0.7" }
-Sep 16 00:44:55 spaceman fail2ban.server.actions: NOTICE [jail] Ban 10.0.0.7
+Sep 16 00:44:55 spaceman fail2ban.actions: NOTICE [jail] Ban 10.0.0.7
 
 # failJSON: { "time": "2006-02-13T15:52:30", "match": true , "host": "1.2.3.4", "desc": "Extended with [PID] and padding" }
-2006-02-13 15:52:30,388 fail2ban.server.actions[123]: NOTICE  [sendmail] Ban 1.2.3.4
+2006-02-13 15:52:30,388 fail2ban.actions        [123]: NOTICE  [sendmail] Ban 1.2.3.4

fail2ban/tests/servertestcase.py

@@ -35,6 +35,7 @@ import logging
 from ..server.failregex import Regex, FailRegex, RegexException
 from ..server.server import Server
 from ..server.jail import Jail
+from ..helpers import getF2BLogger
 
 try:
 	from ..server import filtersystemd
@@ -722,7 +723,7 @@ class TransmitterLogging(TransmitterBase):
 			os.close(f)
 			self.server.setLogLevel("WARNING")
 			self.assertEqual(self.transm.proceed(["set", "logtarget", fn]), (0, fn))
-			l = logging.getLogger('fail2ban.server.server').parent.parent
+			l = logging.getLogger('fail2ban')
 			l.warning("Before file moved")
 			try:
 				f2, fn2 = tempfile.mkstemp("fail2ban.log")
@@ -796,5 +797,10 @@ class RegexTests(unittest.TestCase):
 		self.assertTrue(fr.hasMatched())
 		self.assertRaises(RegexException, fr.getHost)
 
+class LoggingTests(unittest.TestCase):
 
+	def testGetF2BLogger(self):
+		testLogSys = getF2BLogger("fail2ban.some.string.with.name")
+		self.assertEqual(testLogSys.parent.name, "fail2ban")
+		self.assertEqual(testLogSys.name, "fail2ban.name")
 

fail2ban/tests/utils.py

@@ -30,8 +30,9 @@ import unittest
 from StringIO import StringIO
 
 from ..server.mytime import MyTime
+from ..helpers import getF2BLogger
 
-logSys = logging.getLogger(__name__)
+logSys = getF2BLogger(__name__)
 
 def mtimesleep():
 	# no sleep now should be necessary since polling tracks now not only
@@ -89,6 +90,7 @@ def gatherTests(regexps=None, no_network=False):
 	tests.addTest(unittest.makeSuite(servertestcase.Transmitter))
 	tests.addTest(unittest.makeSuite(servertestcase.JailTests))
 	tests.addTest(unittest.makeSuite(servertestcase.RegexTests))
+	tests.addTest(unittest.makeSuite(servertestcase.LoggingTests))
 	tests.addTest(unittest.makeSuite(actiontestcase.CommandActionTest))
 	tests.addTest(unittest.makeSuite(actionstestcase.ExecuteActions))
 	# FailManager