ansible: redirect logging into display 'framework'. closes #111

ansible_mitogen/logging.py

+# Copyright 2017, David Wilson
+#
+# Redistribution and use in source and binary forms, with or without
+# modification, are permitted provided that the following conditions are met:
+#
+# 1. Redistributions of source code must retain the above copyright notice,
+# this list of conditions and the following disclaimer.
+#
+# 2. Redistributions in binary form must reproduce the above copyright notice,
+# this list of conditions and the following disclaimer in the documentation
+# and/or other materials provided with the distribution.
+#
+# 3. Neither the name of the copyright holder nor the names of its contributors
+# may be used to endorse or promote products derived from this software without
+# specific prior written permission.
+#
+# THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS"
+# AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
+# IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
+# ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT HOLDER OR CONTRIBUTORS BE
+# LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR
+# CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF
+# SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS
+# INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN
+# CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE)
+# ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE
+# POSSIBILITY OF SUCH DAMAGE.
+
+from __future__ import absolute_import
+import logging
+import os
+import sys
+
+import mitogen.core
+import mitogen.utils
+
+
+class Handler(logging.Handler):
+    """
+    Use Mitogen's log format, but send the result to a Display method.
+    """
+    def __init__(self, method):
+        super(Handler, self).__init__()
+        self.formatter = mitogen.utils.log_get_formatter()
+        self.method = method
+
+    def emit(self, record):
+        self.method(self.format(record))
+
+
+def find_display():
+    """
+    Find the CLI tool's display variable somewhere up the stack. Why god why,
+    right? Because it's the the simplest way to get access to the verbosity
+    configured on the command line.
+    """
+    f = sys._getframe()
+    while f:
+        if 'display' in f.f_locals:
+            return f.f_locals['display']
+        f = f.f_back
+
+
+def setup():
+    """
+    Install a handler for Mitogen's logger to redirect it into the Ansible
+    display framework, and prevent propagation to the root logger.
+    """
+    display = find_display()
+
+    mitogen.core.LOG.propagate = False
+    mitogen.core.LOG.handlers = [Handler(display.v)]
+    mitogen.core.LOG.setLevel(logging.DEBUG)
+
+    mitogen.core.IOLOG.propagate = False
+    mitogen.core.IOLOG.handlers = [Handler(display.vvvv)]
+    if display.verbosity > 3:
+        mitogen.core.IOLOG.setLevel(logging.DEBUG)

ansible_mitogen/strategy.py

@@ -38,6 +38,7 @@ import mitogen.utils
 
 import ansible.errors
 import ansible.plugins.strategy.linear
+import ansible_mitogen.logging
 import ansible_mitogen.mixins
 import ansible_mitogen.services
 
@@ -176,7 +177,6 @@ class StrategyModule(ansible.plugins.strategy.linear.StrategyModule):
         Arrange for a mitogen.master.Router to be available for the duration of
         the strategy's real run() method.
         """
-        mitogen.utils.log_to_file()
         self._setup_master()
         self._setup_services()
         try:
@@ -216,6 +216,7 @@ class StrategyModule(ansible.plugins.strategy.linear.StrategyModule):
         action_loader.add_directory(os.path.join(base_dir, 'actions'))
 
     def run(self, iterator, play_context, result=0):
+        ansible_mitogen.logging.setup()
         self._add_connection_plugin_path()
         self._install_wrappers()
         try:

mitogen/utils.py

@@ -50,11 +50,19 @@ def _formatTime(record, datefmt=None):
     return dt.strftime(datefmt)
 
 
-def log_to_file(path=None, io=False, usec=False, level='INFO'):
-    io = ('MITOGEN_LOG_IO' in os.environ) or io
+def log_get_formatter(usec=False):
     usec = ('MITOGEN_LOG_USEC' in os.environ) or usec
-    level = os.environ.get('MITOGEN_LOG_LEVEL', level).upper()
+    datefmt = '%H:%M:%S'
+    if usec:
+        datefmt += '.%f'
+
+    fmt = '%(asctime)s %(levelname).1s %(name)s: %(message)s'
+    formatter = logging.Formatter(fmt, datefmt)
+    formatter.formatTime = _formatTime
+    return formatter
+
 
+def log_to_file(path=None, io=False, usec=False, level='INFO'):
     log = logging.getLogger('')
     if path:
         fp = open(path, 'w', 1)
@@ -62,18 +70,16 @@ def log_to_file(path=None, io=False, usec=False, level='INFO'):
     else:
         fp = sys.stderr
 
+    level = os.environ.get('MITOGEN_LOG_LEVEL', level).upper()
     level = getattr(logging, level, logging.INFO)
     log.setLevel(level)
+
+    io = ('MITOGEN_LOG_IO' in os.environ) or io
     if io:
         logging.getLogger('mitogen.io').setLevel(level)
 
-    fmt = '%(asctime)s %(levelname).1s %(name)s: %(message)s'
-    datefmt = '%H:%M:%S'
-    if usec:
-        datefmt += '.%f'
     handler = logging.StreamHandler(fp)
-    handler.formatter = logging.Formatter(fmt, datefmt)
-    handler.formatter.formatTime = _formatTime
+    handler.formatter = log_get_formatter(usec=usec)
     log.handlers.insert(0, handler)