summaryrefslogtreecommitdiffstats
path: root/deluge/log.py
blob: bf4f3c2d776d431468aaa80a36b73f886f2c03a5 (plain)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
# -*- coding: utf-8 -*-
#
# Copyright (C) 2007 Andrew Resch <andrewresch@gmail.com>
# Copyright (C) 2010 Pedro Algarvio <pedro@algarvio.me>
#
# This file is part of Deluge and is licensed under GNU General Public License 3.0, or later, with
# the additional special exception to link portions of this program with the OpenSSL library.
# See LICENSE for more details.
#

"""Logging functions"""
from __future__ import unicode_literals

import inspect
import logging
import logging.handlers
import os
import sys

from twisted.internet import defer
from twisted.python.log import PythonLoggingObserver

from deluge import common

__all__ = ('setup_logger', 'set_logger_level', 'get_plugin_logger', 'LOG')

LoggingLoggerClass = logging.getLoggerClass()

if 'dev' in common.get_version():
    DEFAULT_LOGGING_FORMAT = '%%(asctime)s.%%(msecs)03.0f [%%(levelname)-8s][%%(name)-%ds:%%(lineno)-4d] %%(message)s'
else:
    DEFAULT_LOGGING_FORMAT = (
        '%%(asctime)s [%%(levelname)-8s][%%(name)-%ds:%%(lineno)-4d] %%(message)s'
    )
MAX_LOGGER_NAME_LENGTH = 10


class Logging(LoggingLoggerClass):
    def __init__(self, logger_name):
        super(Logging, self).__init__(logger_name)

        # This makes module name padding increase to the biggest module name
        # so that logs keep readability.
        global MAX_LOGGER_NAME_LENGTH
        if len(logger_name) > MAX_LOGGER_NAME_LENGTH:
            MAX_LOGGER_NAME_LENGTH = len(logger_name)
            for handler in logging.getLogger().handlers:
                handler.setFormatter(
                    logging.Formatter(
                        DEFAULT_LOGGING_FORMAT % MAX_LOGGER_NAME_LENGTH,
                        datefmt='%H:%M:%S',
                    )
                )

    @defer.inlineCallbacks
    def garbage(self, msg, *args, **kwargs):
        yield LoggingLoggerClass.log(self, 1, msg, *args, **kwargs)

    @defer.inlineCallbacks
    def trace(self, msg, *args, **kwargs):
        yield LoggingLoggerClass.log(self, 5, msg, *args, **kwargs)

    @defer.inlineCallbacks
    def debug(self, msg, *args, **kwargs):
        yield LoggingLoggerClass.debug(self, msg, *args, **kwargs)

    @defer.inlineCallbacks
    def info(self, msg, *args, **kwargs):
        yield LoggingLoggerClass.info(self, msg, *args, **kwargs)

    @defer.inlineCallbacks
    def warning(self, msg, *args, **kwargs):
        yield LoggingLoggerClass.warning(self, msg, *args, **kwargs)

    warn = warning

    @defer.inlineCallbacks
    def error(self, msg, *args, **kwargs):
        yield LoggingLoggerClass.error(self, msg, *args, **kwargs)

    @defer.inlineCallbacks
    def critical(self, msg, *args, **kwargs):
        yield LoggingLoggerClass.critical(self, msg, *args, **kwargs)

    @defer.inlineCallbacks
    def exception(self, msg, *args, **kwargs):
        yield LoggingLoggerClass.exception(self, msg, *args, **kwargs)

    def findCaller(self, *args, **kwargs):  # NOQA: N802
        f = logging.currentframe().f_back
        rv = ('(unknown file)', 0, '(unknown function)', None)
        while hasattr(f, 'f_code'):
            co = f.f_code
            filename = os.path.normcase(co.co_filename)
            if filename in (
                __file__.replace('.pyc', '.py'),
                defer.__file__.replace('.pyc', '.py'),
            ):
                f = f.f_back
                continue
            rv = (co.co_filename, f.f_lineno, co.co_name, None)
            break
        if common.PY2:
            return rv[:-1]
        else:
            return rv


levels = {
    'info': logging.INFO,
    'warn': logging.WARNING,
    'warning': logging.WARNING,
    'error': logging.ERROR,
    'none': logging.CRITICAL,
    'debug': logging.DEBUG,
    'trace': 5,
    'garbage': 1,
}


def setup_logger(
    level='error',
    filename=None,
    filemode='w',
    logrotate=None,
    output_stream=sys.stdout,
    twisted_observer=True,
):
    """
    Sets up the basic logger and if `:param:filename` is set, then it will log
    to that file instead of stdout.

    Args:
        level (str): The log level to use (Default: 'error')
        filename (str, optional): The log filename. Default is None meaning log
                                  to terminal
        filemode (str): The filemode to use when opening the log file
        logrotate (int, optional): The size of the logfile in bytes when enabling
                                   log rotation (Default is None meaning disabled)
        output_stream (file descriptor): File descriptor to log to if not logging to file
        twisted_observer (bool): Whether to setup the custom twisted logging observer.
    """
    if logging.getLoggerClass() is not Logging:
        logging.setLoggerClass(Logging)
        logging.addLevelName(levels['trace'], 'TRACE')
        logging.addLevelName(levels['garbage'], 'GARBAGE')

    level = levels.get(level, logging.ERROR)

    root_logger = logging.getLogger()

    if filename and logrotate:
        handler = logging.handlers.RotatingFileHandler(
            filename, maxBytes=logrotate, backupCount=5, encoding='utf-8'
        )
    elif filename and filemode == 'w':
        handler_cls = logging.FileHandler
        if not common.windows_check():
            handler_cls = getattr(
                logging.handlers, 'WatchedFileHandler', logging.FileHandler
            )
        handler = handler_cls(filename, mode=filemode, encoding='utf-8')
    else:
        handler = logging.StreamHandler(stream=output_stream)

    handler.setLevel(level)

    formatter = logging.Formatter(
        DEFAULT_LOGGING_FORMAT % MAX_LOGGER_NAME_LENGTH, datefmt='%H:%M:%S'
    )

    handler.setFormatter(formatter)

    # Check for existing handler to prevent duplicate logging.
    if root_logger.handlers:
        for handle in root_logger.handlers:
            if not isinstance(handle, type(handler)):
                root_logger.addHandler(handler)
    else:
        root_logger.addHandler(handler)
    root_logger.setLevel(level)

    if twisted_observer:
        twisted_logging = TwistedLoggingObserver()
        twisted_logging.start()


class TwistedLoggingObserver(PythonLoggingObserver):
    """
    Custom logging class to fix missing exception tracebacks in log output with new
    twisted.logger module in twisted version >= 15.2.

    Related twisted bug ticket: https://twistedmatrix.com/trac/ticket/7927

    """

    def __init__(self):
        PythonLoggingObserver.__init__(self, loggerName='twisted')

    def emit(self, event_dict):
        log = logging.getLogger(__name__)
        if 'log_failure' in event_dict:
            fmt = '%(log_namespace)s \n%(log_failure)s'
            getattr(LoggingLoggerClass, event_dict['log_level'].name)(
                log, fmt % (event_dict)
            )
        else:
            PythonLoggingObserver.emit(self, event_dict)


def tweak_logging_levels():
    """This function allows tweaking the logging levels for all or some loggers.
    This is mostly usefull for developing purposes hence the contents of the
    file are NOT like regular deluge config file's.

    To use is, create a file named "logging.conf" on your Deluge's config dir
    with contents like for example:
        deluge:warn
        deluge.core:debug
        deluge.plugin:error

    What the above mean is the logger "deluge" will be set to the WARN level,
    the "deluge.core" logger will be set to the DEBUG level and the
    "deluge.plugin" will be set to the ERROR level.

    Remember, one rule per line and this WILL override the setting passed from
    the command line.
    """
    from deluge import configmanager

    logging_config_file = os.path.join(configmanager.get_config_dir(), 'logging.conf')
    if not os.path.isfile(logging_config_file):
        return
    log = logging.getLogger(__name__)
    log.warning(
        'logging.conf found! tweaking logging levels from %s', logging_config_file
    )
    with open(logging_config_file, 'r') as _file:
        for line in _file:
            if line.strip().startswith('#'):
                continue
            name, level = line.strip().split(':')
            if level not in levels:
                continue

            log.warning('Setting logger "%s" to logging level "%s"', name, level)
            set_logger_level(level, name)


def set_logger_level(level, logger_name=None):
    """
    Sets the logger level.

    :param level: str, a string representing the desired level
    :param logger_name: str, a string representing desired logger name for which
                        the level should change. The default is "None" will tweak
                        the root logger level.

    """
    logging.getLogger(logger_name).setLevel(levels.get(level, 'error'))


def get_plugin_logger(logger_name):
    import warnings

    stack = inspect.stack()
    stack.pop(0)  # The logging call from this module
    module_stack = stack.pop(0)  # The module that called the log function
    caller_module = inspect.getmodule(module_stack[0])
    # In some weird cases caller_module might be None, try to continue
    caller_module_name = getattr(caller_module, '__name__', '')
    warnings.warn_explicit(
        DEPRECATION_WARNING,
        DeprecationWarning,
        module_stack[1],
        module_stack[2],
        caller_module_name,
    )

    if 'deluge.plugins.' in logger_name:
        return logging.getLogger(logger_name)
    return logging.getLogger('deluge.plugin.%s' % logger_name)


DEPRECATION_WARNING = """You seem to be using old style logging on your code, ie:
    from deluge.log import LOG as log

or:
    from deluge.log import get_plugin_logger

This has been deprecated in favour of an enhanced logging system and both "LOG"
and "get_plugin_logger" will be removed on the next major version release of Deluge,
meaning, code will break, specially plugins.
If you're seeing this message and you're not the developer of the plugin which
triggered this warning, please report to it's author.
If you're the developer, please stop using the above code and instead use:

   import logging
   log = logging.getLogger(__name__)


The above will result in, regarding the "Label" plugin for example a log message similar to:
   15:33:54 [deluge.plugins.label.core:78  ][INFO    ] *** Start Label plugin ***

Triggering code:
"""


class _BackwardsCompatibleLOG(object):
    def __getattribute__(self, name):
        import warnings

        logger_name = 'deluge'
        stack = inspect.stack()
        stack.pop(0)  # The logging call from this module
        module_stack = stack.pop(0)  # The module that called the log function
        caller_module = inspect.getmodule(module_stack[0])
        # In some weird cases caller_module might be None, try to continue
        caller_module_name = getattr(caller_module, '__name__', '')
        warnings.warn_explicit(
            DEPRECATION_WARNING,
            DeprecationWarning,
            module_stack[1],
            module_stack[2],
            caller_module_name,
        )
        if caller_module:
            for member in stack:
                module = inspect.getmodule(member[0])
                if not module:
                    continue
                if module.__name__ in (
                    'deluge.plugins.pluginbase',
                    'deluge.plugins.init',
                ):
                    logger_name += '.plugin.%s' % caller_module_name
                    # Monkey Patch The Plugin Module
                    caller_module.log = logging.getLogger(logger_name)
                    break
        else:
            logging.getLogger(logger_name).warning(
                "Unable to monkey-patch the calling module's `log` attribute! "
                'You should really update and rebuild your plugins...'
            )
        return getattr(logging.getLogger(logger_name), name)


LOG = _BackwardsCompatibleLOG()