File size: 19,898 Bytes
b72ab63
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
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
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
375
376
377
378
379
380
381
382
383
384
385
386
387
388
389
390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
407
408
409
410
411
412
413
414
415
416
417
418
419
420
421
422
423
424
425
426
427
428
429
430
431
432
433
434
435
436
437
438
439
440
441
442
443
444
445
446
447
448
449
450
451
452
453
454
455
456
457
458
459
460
461
462
463
464
465
466
467
468
469
470
471
472
473
474
475
476
477
478
479
480
481
482
483
484
485
486
487
488
489
490
491
492
493
494
495
496
497
498
499
500
501
502
503
504
505
506
507
508
509
510
511
512
513
514
515
516
517
518
519
520
521
522
523
524
525
526
527
528
529
530
531
532
533
534
535
536
537
538
539
540
541
542
543
544
import sys
import logging
import timeit
from functools import wraps
from collections.abc import Mapping, Callable
import warnings
from logging import PercentStyle


# default logging level used by Timer class
TIME_LEVEL = logging.DEBUG

# per-level format strings used by the default formatter
# (the level name is not printed for INFO and DEBUG messages)
DEFAULT_FORMATS = {
    "*": "%(levelname)s: %(message)s",
    "INFO": "%(message)s",
    "DEBUG": "%(message)s",
}


class LevelFormatter(logging.Formatter):
    """Log formatter with level-specific formatting.

    Formatter class which optionally takes a dict of logging levels to
    format strings, allowing to customise the log records appearance for
    specific levels.


    Attributes:
            fmt: A dictionary mapping logging levels to format strings.
                    The ``*`` key identifies the default format string.
            datefmt: As per py:class:`logging.Formatter`
            style: As per py:class:`logging.Formatter`

    >>> import sys
    >>> handler = logging.StreamHandler(sys.stdout)
    >>> formatter = LevelFormatter(
    ...     fmt={
    ...         '*':     '[%(levelname)s] %(message)s',
    ...         'DEBUG': '%(name)s [%(levelname)s] %(message)s',
    ...         'INFO':  '%(message)s',
    ...     })
    >>> handler.setFormatter(formatter)
    >>> log = logging.getLogger('test')
    >>> log.setLevel(logging.DEBUG)
    >>> log.addHandler(handler)
    >>> log.debug('this uses a custom format string')
    test [DEBUG] this uses a custom format string
    >>> log.info('this also uses a custom format string')
    this also uses a custom format string
    >>> log.warning("this one uses the default format string")
    [WARNING] this one uses the default format string
    """

    def __init__(self, fmt=None, datefmt=None, style="%"):
        if style != "%":
            raise ValueError(
                "only '%' percent style is supported in both python 2 and 3"
            )
        if fmt is None:
            fmt = DEFAULT_FORMATS
        if isinstance(fmt, str):
            default_format = fmt
            custom_formats = {}
        elif isinstance(fmt, Mapping):
            custom_formats = dict(fmt)
            default_format = custom_formats.pop("*", None)
        else:
            raise TypeError("fmt must be a str or a dict of str: %r" % fmt)
        super(LevelFormatter, self).__init__(default_format, datefmt)
        self.default_format = self._fmt
        self.custom_formats = {}
        for level, fmt in custom_formats.items():
            level = logging._checkLevel(level)
            self.custom_formats[level] = fmt

    def format(self, record):
        if self.custom_formats:
            fmt = self.custom_formats.get(record.levelno, self.default_format)
            if self._fmt != fmt:
                self._fmt = fmt
                # for python >= 3.2, _style needs to be set if _fmt changes
                if PercentStyle:
                    self._style = PercentStyle(fmt)
        return super(LevelFormatter, self).format(record)


def configLogger(**kwargs):
    """A more sophisticated logging system configuation manager.

    This is more or less the same as :py:func:`logging.basicConfig`,
    with some additional options and defaults.

    The default behaviour is to create a ``StreamHandler`` which writes to
    sys.stderr, set a formatter using the ``DEFAULT_FORMATS`` strings, and add
    the handler to the top-level library logger ("fontTools").

    A number of optional keyword arguments may be specified, which can alter
    the default behaviour.

    Args:

            logger: Specifies the logger name or a Logger instance to be
                    configured. (Defaults to "fontTools" logger). Unlike ``basicConfig``,
                    this function can be called multiple times to reconfigure a logger.
                    If the logger or any of its children already exists before the call is
                    made, they will be reset before the new configuration is applied.
            filename: Specifies that a ``FileHandler`` be created, using the
                    specified filename, rather than a ``StreamHandler``.
            filemode: Specifies the mode to open the file, if filename is
                    specified. (If filemode is unspecified, it defaults to ``a``).
            format: Use the specified format string for the handler. This
                    argument also accepts a dictionary of format strings keyed by
                    level name, to allow customising the records appearance for
                    specific levels. The special ``'*'`` key is for 'any other' level.
            datefmt: Use the specified date/time format.
            level: Set the logger level to the specified level.
            stream: Use the specified stream to initialize the StreamHandler. Note
                    that this argument is incompatible with ``filename`` - if both
                    are present, ``stream`` is ignored.
            handlers: If specified, this should be an iterable of already created
                    handlers, which will be added to the logger. Any handler in the
                    list which does not have a formatter assigned will be assigned the
                    formatter created in this function.
            filters: If specified, this should be an iterable of already created
                    filters. If the ``handlers`` do not already have filters assigned,
                    these filters will be added to them.
            propagate: All loggers have a ``propagate`` attribute which determines
                    whether to continue searching for handlers up the logging hierarchy.
                    If not provided, the "propagate" attribute will be set to ``False``.
    """
    # using kwargs to enforce keyword-only arguments in py2.
    handlers = kwargs.pop("handlers", None)
    if handlers is None:
        if "stream" in kwargs and "filename" in kwargs:
            raise ValueError(
                "'stream' and 'filename' should not be " "specified together"
            )
    else:
        if "stream" in kwargs or "filename" in kwargs:
            raise ValueError(
                "'stream' or 'filename' should not be "
                "specified together with 'handlers'"
            )
    if handlers is None:
        filename = kwargs.pop("filename", None)
        mode = kwargs.pop("filemode", "a")
        if filename:
            h = logging.FileHandler(filename, mode)
        else:
            stream = kwargs.pop("stream", None)
            h = logging.StreamHandler(stream)
        handlers = [h]
    # By default, the top-level library logger is configured.
    logger = kwargs.pop("logger", "fontTools")
    if not logger or isinstance(logger, str):
        # empty "" or None means the 'root' logger
        logger = logging.getLogger(logger)
    # before (re)configuring, reset named logger and its children (if exist)
    _resetExistingLoggers(parent=logger.name)
    # use DEFAULT_FORMATS if 'format' is None
    fs = kwargs.pop("format", None)
    dfs = kwargs.pop("datefmt", None)
    # XXX: '%' is the only format style supported on both py2 and 3
    style = kwargs.pop("style", "%")
    fmt = LevelFormatter(fs, dfs, style)
    filters = kwargs.pop("filters", [])
    for h in handlers:
        if h.formatter is None:
            h.setFormatter(fmt)
        if not h.filters:
            for f in filters:
                h.addFilter(f)
        logger.addHandler(h)
    if logger.name != "root":
        # stop searching up the hierarchy for handlers
        logger.propagate = kwargs.pop("propagate", False)
    # set a custom severity level
    level = kwargs.pop("level", None)
    if level is not None:
        logger.setLevel(level)
    if kwargs:
        keys = ", ".join(kwargs.keys())
        raise ValueError("Unrecognised argument(s): %s" % keys)


def _resetExistingLoggers(parent="root"):
    """Reset the logger named 'parent' and all its children to their initial
    state, if they already exist in the current configuration.
    """
    root = logging.root
    # get sorted list of all existing loggers
    existing = sorted(root.manager.loggerDict.keys())
    if parent == "root":
        # all the existing loggers are children of 'root'
        loggers_to_reset = [parent] + existing
    elif parent not in existing:
        # nothing to do
        return
    elif parent in existing:
        loggers_to_reset = [parent]
        # collect children, starting with the entry after parent name
        i = existing.index(parent) + 1
        prefixed = parent + "."
        pflen = len(prefixed)
        num_existing = len(existing)
        while i < num_existing:
            if existing[i][:pflen] == prefixed:
                loggers_to_reset.append(existing[i])
            i += 1
    for name in loggers_to_reset:
        if name == "root":
            root.setLevel(logging.WARNING)
            for h in root.handlers[:]:
                root.removeHandler(h)
            for f in root.filters[:]:
                root.removeFilters(f)
            root.disabled = False
        else:
            logger = root.manager.loggerDict[name]
            logger.level = logging.NOTSET
            logger.handlers = []
            logger.filters = []
            logger.propagate = True
            logger.disabled = False


class Timer(object):
    """Keeps track of overall time and split/lap times.

    >>> import time
    >>> timer = Timer()
    >>> time.sleep(0.01)
    >>> print("First lap:", timer.split())
    First lap: ...
    >>> time.sleep(0.02)
    >>> print("Second lap:", timer.split())
    Second lap: ...
    >>> print("Overall time:", timer.time())
    Overall time: ...

    Can be used as a context manager inside with-statements.

    >>> with Timer() as t:
    ...     time.sleep(0.01)
    >>> print("%0.3f seconds" % t.elapsed)
    0... seconds

    If initialised with a logger, it can log the elapsed time automatically
    upon exiting the with-statement.

    >>> import logging
    >>> log = logging.getLogger("my-fancy-timer-logger")
    >>> configLogger(logger=log, level="DEBUG", format="%(message)s", stream=sys.stdout)
    >>> with Timer(log, 'do something'):
    ...     time.sleep(0.01)
    Took ... to do something

    The same Timer instance, holding a reference to a logger, can be reused
    in multiple with-statements, optionally with different messages or levels.

    >>> timer = Timer(log)
    >>> with timer():
    ...     time.sleep(0.01)
    elapsed time: ...s
    >>> with timer('redo it', level=logging.INFO):
    ...     time.sleep(0.02)
    Took ... to redo it

    It can also be used as a function decorator to log the time elapsed to run
    the decorated function.

    >>> @timer()
    ... def test1():
    ...    time.sleep(0.01)
    >>> @timer('run test 2', level=logging.INFO)
    ... def test2():
    ...    time.sleep(0.02)
    >>> test1()
    Took ... to run 'test1'
    >>> test2()
    Took ... to run test 2
    """

    # timeit.default_timer choses the most accurate clock for each platform
    _time = timeit.default_timer
    default_msg = "elapsed time: %(time).3fs"
    default_format = "Took %(time).3fs to %(msg)s"

    def __init__(self, logger=None, msg=None, level=None, start=None):
        self.reset(start)
        if logger is None:
            for arg in ("msg", "level"):
                if locals().get(arg) is not None:
                    raise ValueError("'%s' can't be specified without a 'logger'" % arg)
        self.logger = logger
        self.level = level if level is not None else TIME_LEVEL
        self.msg = msg

    def reset(self, start=None):
        """Reset timer to 'start_time' or the current time."""
        if start is None:
            self.start = self._time()
        else:
            self.start = start
        self.last = self.start
        self.elapsed = 0.0

    def time(self):
        """Return the overall time (in seconds) since the timer started."""
        return self._time() - self.start

    def split(self):
        """Split and return the lap time (in seconds) in between splits."""
        current = self._time()
        self.elapsed = current - self.last
        self.last = current
        return self.elapsed

    def formatTime(self, msg, time):
        """Format 'time' value in 'msg' and return formatted string.
        If 'msg' contains a '%(time)' format string, try to use that.
        Otherwise, use the predefined 'default_format'.
        If 'msg' is empty or None, fall back to 'default_msg'.
        """
        if not msg:
            msg = self.default_msg
        if msg.find("%(time)") < 0:
            msg = self.default_format % {"msg": msg, "time": time}
        else:
            try:
                msg = msg % {"time": time}
            except (KeyError, ValueError):
                pass  # skip if the format string is malformed
        return msg

    def __enter__(self):
        """Start a new lap"""
        self.last = self._time()
        self.elapsed = 0.0
        return self

    def __exit__(self, exc_type, exc_value, traceback):
        """End the current lap. If timer has a logger, log the time elapsed,
        using the format string in self.msg (or the default one).
        """
        time = self.split()
        if self.logger is None or exc_type:
            # if there's no logger attached, or if any exception occurred in
            # the with-statement, exit without logging the time
            return
        message = self.formatTime(self.msg, time)
        # Allow log handlers to see the individual parts to facilitate things
        # like a server accumulating aggregate stats.
        msg_parts = {"msg": self.msg, "time": time}
        self.logger.log(self.level, message, msg_parts)

    def __call__(self, func_or_msg=None, **kwargs):
        """If the first argument is a function, return a decorator which runs
        the wrapped function inside Timer's context manager.
        Otherwise, treat the first argument as a 'msg' string and return an updated
        Timer instance, referencing the same logger.
        A 'level' keyword can also be passed to override self.level.
        """
        if isinstance(func_or_msg, Callable):
            func = func_or_msg
            # use the function name when no explicit 'msg' is provided
            if not self.msg:
                self.msg = "run '%s'" % func.__name__

            @wraps(func)
            def wrapper(*args, **kwds):
                with self:
                    return func(*args, **kwds)

            return wrapper
        else:
            msg = func_or_msg or kwargs.get("msg")
            level = kwargs.get("level", self.level)
            return self.__class__(self.logger, msg, level)

    def __float__(self):
        return self.elapsed

    def __int__(self):
        return int(self.elapsed)

    def __str__(self):
        return "%.3f" % self.elapsed


class ChannelsFilter(logging.Filter):
    """Provides a hierarchical filter for log entries based on channel names.

    Filters out records emitted from a list of enabled channel names,
    including their children. It works the same as the ``logging.Filter``
    class, but allows the user to specify multiple channel names.

    >>> import sys
    >>> handler = logging.StreamHandler(sys.stdout)
    >>> handler.setFormatter(logging.Formatter("%(message)s"))
    >>> filter = ChannelsFilter("A.B", "C.D")
    >>> handler.addFilter(filter)
    >>> root = logging.getLogger()
    >>> root.addHandler(handler)
    >>> root.setLevel(level=logging.DEBUG)
    >>> logging.getLogger('A.B').debug('this record passes through')
    this record passes through
    >>> logging.getLogger('A.B.C').debug('records from children also pass')
    records from children also pass
    >>> logging.getLogger('C.D').debug('this one as well')
    this one as well
    >>> logging.getLogger('A.B.').debug('also this one')
    also this one
    >>> logging.getLogger('A.F').debug('but this one does not!')
    >>> logging.getLogger('C.DE').debug('neither this one!')
    """

    def __init__(self, *names):
        self.names = names
        self.num = len(names)
        self.lengths = {n: len(n) for n in names}

    def filter(self, record):
        if self.num == 0:
            return True
        for name in self.names:
            nlen = self.lengths[name]
            if name == record.name:
                return True
            elif record.name.find(name, 0, nlen) == 0 and record.name[nlen] == ".":
                return True
        return False


class CapturingLogHandler(logging.Handler):
    def __init__(self, logger, level):
        super(CapturingLogHandler, self).__init__(level=level)
        self.records = []
        if isinstance(logger, str):
            self.logger = logging.getLogger(logger)
        else:
            self.logger = logger

    def __enter__(self):
        self.original_disabled = self.logger.disabled
        self.original_level = self.logger.level
        self.original_propagate = self.logger.propagate

        self.logger.addHandler(self)
        self.logger.setLevel(self.level)
        self.logger.disabled = False
        self.logger.propagate = False

        return self

    def __exit__(self, type, value, traceback):
        self.logger.removeHandler(self)
        self.logger.setLevel(self.original_level)
        self.logger.disabled = self.original_disabled
        self.logger.propagate = self.original_propagate

        return self

    def emit(self, record):
        self.records.append(record)

    def assertRegex(self, regexp, msg=None):
        import re

        pattern = re.compile(regexp)
        for r in self.records:
            if pattern.search(r.getMessage()):
                return True
        if msg is None:
            msg = "Pattern '%s' not found in logger records" % regexp
        assert 0, msg


class LogMixin(object):
    """Mixin class that adds logging functionality to another class.

    You can define a new class that subclasses from ``LogMixin`` as well as
    other base classes through multiple inheritance.
    All instances of that class will have a ``log`` property that returns
    a ``logging.Logger`` named after their respective ``<module>.<class>``.

    For example:

    >>> class BaseClass(object):
    ...     pass
    >>> class MyClass(LogMixin, BaseClass):
    ...     pass
    >>> a = MyClass()
    >>> isinstance(a.log, logging.Logger)
    True
    >>> print(a.log.name)
    fontTools.misc.loggingTools.MyClass
    >>> class AnotherClass(MyClass):
    ...     pass
    >>> b = AnotherClass()
    >>> isinstance(b.log, logging.Logger)
    True
    >>> print(b.log.name)
    fontTools.misc.loggingTools.AnotherClass
    """

    @property
    def log(self):
        if not hasattr(self, "_log"):
            name = ".".join((self.__class__.__module__, self.__class__.__name__))
            self._log = logging.getLogger(name)
        return self._log


def deprecateArgument(name, msg, category=UserWarning):
    """Raise a warning about deprecated function argument 'name'."""
    warnings.warn("%r is deprecated; %s" % (name, msg), category=category, stacklevel=3)


def deprecateFunction(msg, category=UserWarning):
    """Decorator to raise a warning when a deprecated function is called."""

    def decorator(func):
        @wraps(func)
        def wrapper(*args, **kwargs):
            warnings.warn(
                "%r is deprecated; %s" % (func.__name__, msg),
                category=category,
                stacklevel=2,
            )
            return func(*args, **kwargs)

        return wrapper

    return decorator


if __name__ == "__main__":
    import doctest

    sys.exit(doctest.testmod(optionflags=doctest.ELLIPSIS).failed)