1#!/usr/bin/env python
2
3# Copyright (c) 2013 The Chromium OS Authors. All rights reserved.
4# Use of this source code is governed by a BSD-style license that can be
5# found in the LICENSE file.
6
7import functools
8import inspect
9import logging
10import traceback
11
12def log_dbus_method(return_logger=logging.debug, raise_logger=logging.warning,
13                    return_cb_arg=None, raise_cb_arg=None):
14    """
15    Factory method for decorator to log dbus responses / errors.
16
17    This method should be used to decorate the most concerete implementation of
18    a dbus method.
19
20    @param return_logger: A function that accepts a string argument to log the
21            response from the decorated function.
22    @param raise_logger: A function accepts a string argument to log the
23            exception raised by the decorated function.
24    @param return_cb_arg: str name of the async callback argument for the return
25            value, if the function takes one.
26    @param raise_cb_arg: str name of the async callback argument for the error
27            return value, if the function takes one.
28
29    """
30    def wrapper(func):
31        """
32        The decorator returned by this factory.
33
34        @param func: The function to be decorated.
35
36        """
37        @functools.wraps(func)
38        def wrapped_func(*args, **kwargs):
39            """The modified function for the decorated function."""
40            modified_args = list(args)
41            modified_kwargs = kwargs
42            return_cb_index = getattr(wrapped_func, '_logging_return_cb_index')
43            if return_cb_index > -1:
44                if len(args) > return_cb_index:
45                    modified_args[return_cb_index] = _wrap_async_return(
46                            args[return_cb_index],
47                            func.__name__,
48                            return_logger)
49                elif return_cb_arg in kwargs:
50                    modified_kwargs[return_cb_arg] = _wrap_async_return(
51                            kwargs[return_cb_arg],
52                            func.__name__,
53                            return_logger)
54                else:
55                    logging.debug('Not logging default return_cb')
56
57            raise_cb_index = getattr(wrapped_func, '_logging_raise_cb_index')
58            if raise_cb_index > -1:
59                if len(args) > raise_cb_index:
60                    modified_args[raise_cb_index] = _wrap_async_raise(
61                            args[raise_cb_index],
62                            func.__name__,
63                            raise_logger)
64                elif raise_cb_arg in kwargs:
65                    modified_kwargs[raise_cb_arg] = _wrap_async_raise(
66                            kwargs[raise_cb_arg],
67                            func.__name__,
68                            raise_logger)
69                else:
70                    logging.debug('Not logging default raise_cb')
71
72            try:
73                retval = func(*modified_args, **modified_kwargs)
74                # No |return_cb_arg| ==> return value is the DBus response, so
75                # it needs to be logged.
76                if return_cb_index == -1:
77                    return_logger('Response[%s] OK: |%s|' % (func.__name__,
78                                                             repr(retval)))
79            except Exception as e:
80                raise_logger('Response[%s] ERROR: |%s|' % (func.__name__,
81                                                           repr(e)))
82                raise_logger(traceback.format_exc())
83                raise
84            return retval
85
86
87        args, _, _, defaults = inspect.getargspec(func)
88        wrapped_func._logging_return_cb_index = -1
89        wrapped_func._logging_raise_cb_index = -1
90        if return_cb_arg:
91            if return_cb_arg not in args:
92                logging.warning(
93                        'Did not find expected argument %s in argument list '
94                        'of %s', return_cb_arg, func.__name__)
95            wrapped_func._logging_return_cb_index = args.index(return_cb_arg)
96        if raise_cb_arg:
97            if raise_cb_arg not in args:
98                logging.warning(
99                        'Did not find expected argument %s in argument list '
100                        'of %s', raise_cb_arg, func.__name__)
101            wrapped_func._logging_raise_cb_index = args.index(raise_cb_arg)
102        return wrapped_func
103    return wrapper
104
105
106def _wrap_async_return(return_cb, fname, logger):
107    """
108    Wrap return_cb to log the return value.
109
110    @param return_cb: The function to be wrapped.
111    @param fname: Name of the DBus function called.
112    @param logger: The logger to use for logging.
113    @returns: Wrapped |return_cb| that additionally logs its arguments.
114
115    """
116    @functools.wraps(return_cb)
117    def wrapped_return_cb(*args, **kwargs):
118        """ Log arguments before calling return_cb. """
119        logger('AsyncResponse[%s] OK: |%s|' % (fname, str((args, kwargs))))
120        return_cb(*args, **kwargs)
121
122    return wrapped_return_cb
123
124
125def _wrap_async_raise(raise_cb, fname, logger):
126    """
127    Wrap raise_cb to log the raised error.
128
129    @param raise_cb: The function to be wrapped.
130    @param fname: Name of the DBus function called.
131    @param logger: The logger to use for logging.
132    @returns: Wrapped |raise_cb| that additionally logs its arguments.
133
134    """
135    @functools.wraps(raise_cb)
136    def wrapped_raise_cb(*args, **kwargs):
137        """ Log arguments before calling raise_cb. """
138        logger('AsyncResponse[%s] ERROR: |%s|' % (fname, str((args, kwargs))))
139        logger(traceback.format_exc())
140        raise_cb(*args, **kwargs)
141
142    return wrapped_raise_cb
143