Remove monkeypatching of warnings in logger

Author: albireox

CHANGELOG.rst

@@ -13,13 +13,13 @@ master
 
 Added
 ^^^^^
-* Added W0621 to diabled list in pylint.
+* Added W0621 to disabled list in pylint.
 
 Changed
 ^^^^^^^
 * Changed documentation font size.
 * Modified code and readthedocs configuration to use Python 3.6.
-* Better logging of warnings. Custom warning are only used when the warning category is a subclass of the base package warning.
+* Remove logger warning monkeypatching since it conflicted when used with packages that provide a similar monkeypatching. Replaced with a custom ``logging.warning`` method that produces coloured warning output.
 * The ``package_name`` specified when cookiecutting the template is applied in lowercase when creating the package but in ucfirst case when creating classes.
 * Renamed ``misc`` to ``utils``.
 

{{cookiecutter.repo_name}}/python/{{cookiecutter.package_name|lower}}/utils/logger.py

@@ -18,20 +18,15 @@
 import sys
 import traceback
 import warnings
-from logging import PercentStyle
 from logging.handlers import TimedRotatingFileHandler
 
 from pygments import highlight
 from pygments.formatters import TerminalFormatter
 from pygments.lexers import get_lexer_by_name
 
-from ..core import exceptions
 from .color_print import color_text
 
 
-# from textwrap import TextWrapper
-
-
 # Adds custom log level for print and twisted messages
 PRINT = 15
 logging.addLevelName(PRINT, 'PRINT')
@@ -56,13 +51,11 @@ def print_exception_formatted(type, value, tb):
 def colored_formatter(record):
     """Prints log messages with colours."""
 
-    colours = {
-        'info': ('blue', 'normal'),
-        'debug': ('magenta', 'normal'),
-        'warning': ('yellow', 'normal'),
-        'print': ('green', 'normal'),
-        'error': ('red', 'bold')
-    }
+    colours = {'info': ('blue', 'normal'),
+               'debug': ('magenta', 'normal'),
+               'warning': ('yellow', 'normal'),
+               'print': ('green', 'normal'),
+               'error': ('red', 'bold')}
 
     levelname = record.levelname.lower()
 
@@ -74,27 +67,15 @@ def colored_formatter(record):
         header = color_text('[{}]: '.format(levelname.upper()),
                             levelname_color)
 
-    message = '{0}'.format(record.msg)
+    message = record.getMessage()
 
-    warning_category = re.match('^(\w+Warning\:).*', message)
-    if warning_category is not None:
-        warning_category_colour = color_text(warning_category.groups()[0],
-                                             'cyan')
-        message = message.replace(warning_category.groups()[0],
-                                  warning_category_colour)
+    if levelname == 'warning':
+        warning_category_groups = re.match(r'^\w*?(.+?Warning) (.*)', message)
+        if warning_category_groups is not None:
+            warning_category, warning_text = warning_category_groups.groups()
 
-    sub_level = re.match('(\[.+\]:)(.*)', message)
-    if sub_level is not None:
-        sub_level_name = color_text(sub_level.groups()[0], 'red')
-        message = '{}{}'.format(sub_level_name, ''.join(
-            sub_level.groups()[1:]))
-
-    # if len(message) > 79:
-    #     tw = TextWrapper()
-    #     tw.width = 79
-    #     tw.subsequent_indent = ' ' * (len(record.levelname) + 2)
-    #     tw.break_on_hyphens = False
-    #     message = '\n'.join(tw.wrap(message))
+            warning_category_colour = color_text('({})'.format(warning_category), 'cyan')
+            message = '{} {}'.format(color_text(warning_text, ''), warning_category_colour)
 
     sys.__stdout__.write('{}{}\n'.format(header, message))
     sys.__stdout__.flush()
@@ -104,42 +85,42 @@ def colored_formatter(record):
 
 class MyFormatter(logging.Formatter):
 
-    warning_fmt = '%(asctime)s - %(levelname)s: %(message)s [%(origin)s]'
-    info_fmt = '%(asctime)s - %(levelname)s - %(message)s [%(funcName)s @ ' + \
-        '%(filename)s]'
+    base_fmt = '%(asctime)s - %(levelname)s - %(message)s [%(funcName)s @ %(filename)s]'
 
     ansi_escape = re.compile(r'\x1b[^m]*m')
 
+    def __init__(self, fmt='%(levelname)s - %(message)s [%(funcName)s @ %(filename)s]'):
+        logging.Formatter.__init__(self, fmt, datefmt='%Y-%m-%d %H:%M:%S')
+
     def format(self, record):
 
         # Save the original format configured by the user
         # when the logger formatter was instantiated
-        # format_orig = self._fmt
+        format_orig = self._fmt
 
         # Replace the original format with one customized by logging level
-
         if record.levelno == logging.DEBUG:
-            self._style = PercentStyle(MyFormatter.info_fmt)
+            self._fmt = MyFormatter.base_fmt
 
         elif record.levelno == logging.getLevelName('PRINT'):
-            self._style = PercentStyle(MyFormatter.info_fmt)
+            self._fmt = MyFormatter.base_fmt
 
         elif record.levelno == logging.INFO:
-            self._style = PercentStyle(MyFormatter.info_fmt)
+            self._fmt = MyFormatter.base_fmt
 
         elif record.levelno == logging.ERROR:
-            self._style = PercentStyle(MyFormatter.info_fmt)
+            self._fmt = MyFormatter.base_fmt
 
         elif record.levelno == logging.WARNING:
-            self._style = PercentStyle(MyFormatter.warning_fmt)
+            self._fmt = MyFormatter.base_fmt
 
         record.msg = self.ansi_escape.sub('', record.msg)
 
         # Call the original formatter class to do the grunt work
         result = logging.Formatter.format(self, record)
 
         # Restore the original format configured by the user
-        # self._fmt = format_orig
+        self._fmt = format_orig
 
         return result
 
@@ -184,28 +165,6 @@ class MyLogger(Logger):
     def save_log(self, path):
         shutil.copyfile(self.log_filename, os.path.expanduser(path))
 
-    def _show_warning(self, message, category, *args, **kwargs):
-
-        if not issubclass(category, exceptions.cookiecutter.package_name[0:1]|upper ~ cookiecutter.package_name[1:]Warning):
-            warnings._showwarning_orig(message, category, *args, **kwargs)
-            return
-
-        message = '{0}: {1}'.format(message.__class__.__name__, message)
-        mod_path = args[0]
-
-        mod_name = None
-        mod_path, ext = os.path.splitext(mod_path)
-        for name, mod in sys.modules.items():
-            path = os.path.splitext(getattr(mod, '__file__', ''))[0]
-            if path == mod_path:
-                mod_name = mod.__name__
-                break
-
-        if mod_name is not None:
-            self.warning(message, extra={'origin': mod_name})
-        else:
-            self.warning(message, extra={'origin': 'no_module'})
-
     def _catch_exceptions(self, exctype, value, tb):
         """Catches all exceptions and logs them."""
 
@@ -215,6 +174,50 @@ def _catch_exceptions(self, exctype, value, tb):
         # First, we print to stdout with some colouring.
         print_exception_formatted(exctype, value, tb)
 
+    def warning(self, msg, category=None, use_filters=True):
+        """Custom ``logging.warning``.
+
+        Behaves like the default ``logging.warning`` but accepts ``category``
+        and ``use_filters`` as arguments. ``category`` is the type of warning
+        we are issuing (defaults to `UserWarning`). If ``use_filters=True``,
+        checks whether there are global filters set for the message or the
+        warning category and behaves accordingly.
+
+        """
+
+        if category is None:
+            category = UserWarning
+
+        full_msg = '{0} {1}'.format(category.__name__, msg)
+
+        n_issued = 0
+        if category in self.warning_registry:
+            if msg in self.warning_registry[category]:
+                n_issued = self.warning_registry[category]
+
+        if use_filters:
+
+            category_filter = None
+            regex_filter = None
+            for warnings_filter in warnings.filters:
+                if issubclass(category, warnings_filter[2]):
+                    category_filter = warnings_filter[0]
+                    regex_filter = warnings_filter[1]
+
+            if (category_filter == 'ignore') or (category_filter == 'once' and n_issued >= 1):
+                if regex_filter is None or regex_filter.search(msg) is not None:
+                    return
+
+            if category_filter == 'error':
+                raise ValueError(full_msg)
+
+        super(MyLogger, self).warning(full_msg)
+
+        if msg in self.warning_registry[category]:
+            self.warning_registry[category][msg] += 1
+        else:
+            self.warning_registry[category][msg] = 1
+
     def _set_defaults(self, log_level=logging.INFO, redirect_stdout=False):
         """Reset logger to its initial state."""
 
@@ -230,25 +233,13 @@ def _set_defaults(self, log_level=logging.INFO, redirect_stdout=False):
 
         self.sh.setLevel(log_level)
 
-        self.enable_warnings()
-
         # Redirects all stdout to the logger
         if redirect_stdout:
             sys.stdout = LoggerStdout(self._print)
 
         # Catches exceptions
         sys.excepthook = self._catch_exceptions
 
-    def enable_warnings(self):
-        """Redirects warnings to the log."""
-
-        warnings.showwarning = self._show_warning
-
-    def disable_warnings(self):
-        """Restores normal warning system."""
-
-        warnings.showwarning = warnings._show_warning
-
     def start_file_logger(self, path, log_file_level=logging.DEBUG):
         """Start file logging."""
 
@@ -269,16 +260,16 @@ def start_file_logger(self, path, log_file_level=logging.DEBUG):
                 str(log_file_path), when='midnight', utc=True)
             self.fh.suffix = '%Y-%m-%d_%H:%M:%S'
         except (IOError, OSError) as ee:
-            warnings.warn('log file {0!r} could not be opened for writing: '
-                          '{1}'.format(log_file_path, ee), RuntimeWarning)
+            self.warning('log file {0!r} could not be opened for writing: {1}'.format(
+                log_file_path, ee), RuntimeWarning)
         else:
             self.fh.setFormatter(fmt)
             self.addHandler(self.fh)
             self.fh.setLevel(log_file_level)
 
             self.log_filename = log_file_path
 
-    def setLevel(self, level):
+    def set_level(self, level):
         """Sets levels for both sh and (if initialised) fh."""
 
         self.sh.setLevel(level)