~facundo/ubuntuone-client/working-speedups

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
# ubuntuone.syncdaemon.logger - logging utilities
#
# Author: Guillermo Gonzalez <guillermo.gonzalez@canonical.com>
#
# Copyright 2010 Canonical Ltd.
#
# This program is free software: you can redistribute it and/or modify it
# under the terms of the GNU General Public License version 3, as published
# by the Free Software Foundation.
#
# This program is distributed in the hope that it will be useful, but
# WITHOUT ANY WARRANTY; without even the implied warranties of
# MERCHANTABILITY, SATISFACTORY QUALITY, or FITNESS FOR A PARTICULAR
# PURPOSE.  See the GNU General Public License for more details.
#
# You should have received a copy of the GNU General Public License along
# with this program.  If not, see <http://www.gnu.org/licenses/>.
"""Ubuntuone client logging utilities and config. """
from __future__ import with_statement

import contextlib
import logging
import sys
import os
import re
import weakref
import functools
import xdg.BaseDirectory

from logging.handlers import TimedRotatingFileHandler

# extra levels
# be more verbose than logging.DEBUG(10)
TRACE = 5
# info that we almost always want to log (logging.ERROR - 1)
NOTE = logging.ERROR - 1

# map names to the extra levels
levels = {'TRACE':TRACE, 'NOTE':NOTE}
for k, v in levels.items():
    logging.addLevelName(v, k)


class Logger(logging.Logger):
    """Logger that support out custom levels."""

    def note(self, msg, *args, **kwargs):
        """log at NOTE level"""
        if self.isEnabledFor(NOTE):
            self._log(NOTE, msg, args, **kwargs)

    def trace(self, msg, *args, **kwargs):
        """log at TRACE level"""
        if self.isEnabledFor(TRACE):
            self._log(TRACE, msg, args, **kwargs)


class DayRotatingFileHandler(TimedRotatingFileHandler):
    """A mix of TimedRotatingFileHandler and RotatingFileHandler configured for
    daily rotation but that uses the suffix and extMatch of Hourly rotation, in
    order to allow seconds based rotation on each startup.
    The log file is also rotated when the specified size is reached.
    """

    def __init__(self, *args, **kwargs):
        """ create the instance and override the suffix and extMatch.
        Also accepts a maxBytes keyword arg to rotate the file when it reachs
        maxBytes.
        """
        kwargs['when'] = 'D'
        kwargs['backupCount'] = LOGBACKUP
        # check if we are in 2.5, only for PQM
        if sys.version_info[:2] >= (2, 6):
            kwargs['delay'] = 1
        if 'maxBytes' in kwargs:
            self.maxBytes = kwargs.pop('maxBytes')
        else:
            self.maxBytes = 0
        TimedRotatingFileHandler.__init__(self, *args, **kwargs)
        # override suffix
        self.suffix = "%Y-%m-%d_%H-%M-%S"
        self.extMatch = re.compile(r"^\d{4}-\d{2}-\d{2}_\d{2}-\d{2}-\d{2}$")

    def shouldRollover(self, record):
        """
        Determine if rollover should occur.

        Basically, see if TimedRotatingFileHandler.shouldRollover and if it's
        False see if the supplied record would cause the file to exceed
        the size limit we have.

        The size based rotation are from logging.handlers.RotatingFileHandler
        """
        if TimedRotatingFileHandler.shouldRollover(self, record):
            return 1
        else:
            # check the size
            if self.stream is None:                 # delay was set...
                self.stream = self._open()
            if self.maxBytes > 0:                   # are we rolling over?
                msg = "%s\n" % self.format(record)
                self.stream.seek(0, 2)  #due to non-posix-compliant Windows feature
                if self.stream.tell() + len(msg) >= self.maxBytes:
                    return 1
            return 0


class MultiFilter(logging.Filter):
    """Our own logging.Filter.

    To allow filter by multiple names in a single handler or logger.

    """

    def __init__(self, names=None):
        logging.Filter.__init__(self)
        self.names = names or []
        self.filters = []
        for name in self.names:
            self.filters.append(logging.Filter(name))

    def filter(self, record):
        """Determine if the specified record is to be logged.

        This work a bit different from the standard logging.Filter, the
        record is logged if at least one filter allows it.
        If there are no filters, the record is allowed.

        """
        if not self.filters:
            # no filters, allow the record
            return True
        for f in self.filters:
            if f.filter(record):
                return True
        return False


class DebugCapture(logging.Handler):
    """
    A context manager to capture debug logs.
    """

    def __init__(self, logger, raise_unhandled=False, on_error=True):
        """Creates the instance.

        @param logger: the logger to wrap
        @param raise_unhandled: raise unhandled errors (which are alse logged)
        @param on_error: if it's True (default) the captured debug info is
        dumped if a record with log level >= ERROR is logged.
        """
        logging.Handler.__init__(self, logging.DEBUG)
        self.on_error = on_error
        self.dirty = False
        self.raise_unhandled = raise_unhandled
        self.records = []
        # insert myself as the handler for the logger
        self.logger = weakref.proxy(logger)
        # store the logger log level
        self.old_level = logger.level
        # remove us from the Handler list and dict
        self.close()

    def emit_debug(self):
        """emit stored records to the original logger handler(s)"""
        enable_debug = self.enable_debug
        for record in self.records:
            for slave in self.slaves:
                with enable_debug(slave):
                    slave.handle(record)

    @contextlib.contextmanager
    def enable_debug(self, obj):
        """context manager that temporarily changes the level attribute of obj
        to logging.DEBUG.
        """
        old_level = obj.level
        obj.level = logging.DEBUG
        yield obj
        obj.level = old_level

    def clear(self):
        """cleanup the captured records"""
        self.records = []

    def install(self):
        """Install the debug capture in the logger"""
        self.slaves = self.logger.handlers
        self.logger.handlers = [self]
        # set the logger level in DEBUG
        self.logger.setLevel(logging.DEBUG)

    def uninstall(self):
        """restore the logger original handlers"""
        # restore the logger
        self.logger.handlers = self.slaves
        self.logger.setLevel(self.old_level)
        self.clear()
        self.dirty = False
        self.slaves = []

    def emit(self, record):
        """A emit() that append the record to the record list"""
        self.records.append(record)

    def handle(self, record):
        """ handle a record """
        # if its a DEBUG level record then intercept otherwise
        # pass through to the original logger handler(s)
        if self.old_level <= logging.DEBUG:
            return sum(slave.handle(record) for slave in self.slaves)
        if record.levelno == logging.DEBUG:
            return logging.Handler.handle(self, record)
        elif self.on_error and record.levelno >= logging.ERROR and \
            record.levelno != NOTE:
            # if it's >= ERROR keep it, but mark the dirty falg
            self.dirty = True
            return logging.Handler.handle(self, record)
        else:
            return sum(slave.handle(record) for slave in self.slaves)

    def __enter__(self):
        """ContextManager API"""
        self.install()
        return self

    def __exit__(self, exc_type, exc_value, traceback):
        """ContextManager API"""
        if exc_type is not None:
            self.emit_debug()
            self.on_error = False
            self.logger.error('unhandled exception', exc_info=(exc_type,
                exc_value, traceback))
        elif self.dirty:
            # emit all debug messages collected after the error
            self.emit_debug()
        self.uninstall()
        if self.raise_unhandled and exc_type is not None:
            raise exc_type, exc_value, traceback
        else:
            return True


### configure the thing ###
# define the location of the log folder
home = xdg.BaseDirectory.xdg_cache_home
LOGFOLDER = os.path.join(home, 'ubuntuone','log')
if not os.path.exists(LOGFOLDER):
    os.makedirs(LOGFOLDER)

LOGBACKUP = 5 # the number of log files to keep around

basic_formatter = logging.Formatter(fmt="%(asctime)s - %(name)s - " \
                                    "%(levelname)s - %(message)s")
debug_formatter = logging.Formatter(fmt="%(asctime)s %(name)s %(module)s " \
                                    "%(lineno)s %(funcName)s %(message)s")

# a constant to change the default DEBUG level value
_DEBUG_LOG_LEVEL = logging.DEBUG


# partial config of the handler to rotate when the file size is 1MB
CustomRotatingFileHandler = functools.partial(DayRotatingFileHandler,
                                              maxBytes=1048576)

# use our logger as the default Logger class
logging.setLoggerClass(Logger)