diff --git a/ansible_mitogen/connection/mitogen.py b/ansible_mitogen/connection/mitogen.py index 4e3c506c..8912bfa2 100644 --- a/ansible_mitogen/connection/mitogen.py +++ b/ansible_mitogen/connection/mitogen.py @@ -26,7 +26,9 @@ # OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. from __future__ import absolute_import +import logging import os +import time import ansible.errors import ansible.plugins.connection @@ -38,6 +40,9 @@ import ansible_mitogen.helpers from ansible_mitogen.strategy.mitogen import ContextService +LOG = logging.getLogger(__name__) + + class Connection(ansible.plugins.connection.ConnectionBase): #: mitogen.master.Router for this worker. router = None @@ -174,7 +179,12 @@ class Connection(ansible.plugins.connection.ConnectionBase): :returns: Function return value. """ - return self.call_async(func, *args, **kwargs).get().unpickle() + t0 = time.time() + try: + return self.call_async(func, *args, **kwargs).get().unpickle() + finally: + LOG.debug('Call %s%r took %d ms', func.func_name, args, + 1000 * (time.time() - t0)) def exec_command(self, cmd, in_data='', sudoable=True): """ diff --git a/docs/api.rst b/docs/api.rst index a3d5f6d1..1050e62a 100644 --- a/docs/api.rst +++ b/docs/api.rst @@ -1000,11 +1000,14 @@ A random assortment of utility functions useful on masters and children. OS X bundles some ancient version of the :py:mod:`six` module. .. currentmodule:: mitogen.utils -.. function:: log_to_file (path=None, io=True, usec=False, level='INFO') +.. function:: log_to_file (path=None, io=False, usec=False, level='INFO') Install a new :py:class:`logging.Handler` writing applications logs to the filesystem. Useful when debugging slave IO problems. + Parameters to this function may be overridden at runtime using environment + variables. See :ref:`logging-env-vars`. + :param str path: If not ``None``, a filesystem path to write logs to. Otherwise, logs are written to :py:data:`sys.stderr`. diff --git a/mitogen/utils.py b/mitogen/utils.py index cd8a93d1..e6d2d6fe 100644 --- a/mitogen/utils.py +++ b/mitogen/utils.py @@ -49,7 +49,7 @@ def _formatTime(record, datefmt=None): return dt.strftime(datefmt) -def log_to_file(path=None, io=True, usec=False, level='INFO'): +def log_to_file(path=None, io=False, usec=False, level='INFO'): io = ('MITOGEN_LOG_IO' in os.environ) or io usec = ('MITOGEN_LOG_USEC' in os.environ) or usec level = os.environ.get('MITOGEN_LOG_LEVEL', level).upper()