diff --git a/.gitignore b/.gitignore index 35a034f..9e99917 100644 --- a/.gitignore +++ b/.gitignore @@ -64,3 +64,5 @@ env* .vagrant flycheck-* +.idea +.python-version diff --git a/.travis.yml b/.travis.yml index daf4277..d924fb1 100644 --- a/.travis.yml +++ b/.travis.yml @@ -1,18 +1,23 @@ language: python +dist: xenial +addons: + apt: + sources: + - chris-lea-redis-server + - sourceline: 'ppa:chris-lea/zeromq' + packages: + - redis-server + - libzmq3-dev services: - redis-server python: - '2.7' - '3.5' - '3.6' -- pypy +- '3.7' before_install: - pip install coveralls install: -- sudo rm -rf /dev/shm && sudo ln -s /run/shm /dev/shm -- sudo apt-add-repository -y ppa:chris-lea/zeromq -- sudo apt-get update -- sudo apt-get install -y libzmq3-dev - pip install -U pip - pip install cython - cython logbook/_speedups.pyx @@ -27,10 +32,6 @@ matrix: exclude: - - python: pypy - env: CYBUILD=True - - python: pypy3 - env: CYBUILD=True include: - python: "3.6" env: GEVENT=True CYBUILD=True @@ -57,6 +58,8 @@ password: secure: WFmuAbtBDIkeZArIFQRCwyO1TdvF2PaZpo75r3mFgnY+aWm75cdgjZKoNqVprF/f+v9EsX2kDdQ7ZfuhMLgP8MNziB+ty7579ZDGwh64jGoi+DIoeblAFu5xNAqjvhie540uCE8KySk9s+Pq5EpOA5w18V4zxTw+h6tnBQ0M9cQ= on: + python: "3.7" + condition: $CYBUILD = 'True' tags: true repo: getlogbook/logbook distributions: "sdist" diff --git a/CHANGES b/CHANGES index a4efec7..4f2c3ac 100644 --- a/CHANGES +++ b/CHANGES @@ -1,5 +1,12 @@ Logbook Changelog ================= + +Version 1.5.1 +------------- + +Released on August 20th, 2019 + +- Added support for asyncio and contextvars Version 1.4.3 ------------- diff --git a/README.md b/README.md index 6d22351..7be09b1 100644 --- a/README.md +++ b/README.md @@ -22,10 +22,10 @@ [ti]: https://secure.travis-ci.org/getlogbook/logbook.svg?branch=master [tl]: https://travis-ci.org/getlogbook/logbook [ai]: https://ci.appveyor.com/api/projects/status/quu99exa26e06npp?svg=true -[vi]: https://img.shields.io/badge/python-2.6%2C2.7%2C3.3%2C3.4%2C3.5-green.svg +[vi]: https://img.shields.io/badge/python-2.7%2C3.5%2C3.6%2C3.7-green.svg [di]: https://img.shields.io/pypi/dm/logbook.svg [al]: https://ci.appveyor.com/project/vmalloc/logbook [pi]: https://img.shields.io/pypi/v/logbook.svg -[pl]: https://pypi.python.org/pypi/Logbook +[pl]: https://pypi.org/pypi/Logbook [ci]: https://coveralls.io/repos/getlogbook/logbook/badge.svg?branch=master&service=github [cl]: https://coveralls.io/github/getlogbook/logbook?branch=master diff --git a/appveyor.yml b/appveyor.yml index 6f11600..6f7ae9c 100644 --- a/appveyor.yml +++ b/appveyor.yml @@ -39,6 +39,14 @@ - PYTHON: "C:\\Python36-x64" CYBUILD: "TRUE" + - PYTHON: "C:\\Python37" + - PYTHON: "C:\\Python37" + CYBUILD: "TRUE" + + - PYTHON: "C:\\Python37-x64" + - PYTHON: "C:\\Python37-x64" + CYBUILD: "TRUE" + init: - echo %PYTHON% - set PATH=%PYTHON%;%PYTHON%\Scripts;%PATH% diff --git a/benchmark/run.py b/benchmark/run.py index 4163c61..da2e3e0 100644 --- a/benchmark/run.py +++ b/benchmark/run.py @@ -2,6 +2,7 @@ """ Runs the benchmarks """ +from __future__ import print_function import sys import os import re @@ -39,14 +40,13 @@ def bench_wrapper(use_gevent=False): - print '=' * 80 - print 'Running benchmark with Logbook %s (gevent enabled=%s)' % \ - (version, use_gevent) - print '-' * 80 + print('=' * 80) + print('Running benchmark with Logbook %s (gevent enabled=%s)' % (version, use_gevent)) + print('-' * 80) os.chdir(bench_directory) for bench in list_benchmarks(): run_bench(bench, use_gevent) - print '-' * 80 + print('-' * 80) def main(): diff --git a/debian/changelog b/debian/changelog index 1898ca7..0b5e55c 100644 --- a/debian/changelog +++ b/debian/changelog @@ -1,3 +1,13 @@ +logbook (1.5.3-1) UNRELEASED; urgency=medium + + [ Iñaki Malerba ] + * Update gitlab-ci.yml + + [ Downstreamer ] + * New upstream version 1.5.3 + + -- Downstreamer Sun, 03 Nov 2019 19:00:25 +0000 + logbook (1.4.3-1) unstable; urgency=medium [ Downstreamer ] diff --git a/docs/index.rst b/docs/index.rst index 44e8dad..9d40b5d 100644 --- a/docs/index.rst +++ b/docs/index.rst @@ -51,6 +51,6 @@ * `Mailing list`_ * IRC: ``#pocoo`` on freenode -.. _Download from PyPI: http://pypi.python.org/pypi/Logbook +.. _Download from PyPI: https://pypi.org/pypi/Logbook .. _Master repository on GitHub: https://github.com/getlogbook/logbook .. _Mailing list: http://groups.google.com/group/pocoo-libs diff --git a/logbook/__version__.py b/logbook/__version__.py index aa56ed4..a06ff4e 100644 --- a/logbook/__version__.py +++ b/logbook/__version__.py @@ -1 +1 @@ -__version__ = "1.4.3" +__version__ = "1.5.3" diff --git a/logbook/_fallback.py b/logbook/_fallback.py index 9f7540e..10fed23 100644 --- a/logbook/_fallback.py +++ b/logbook/_fallback.py @@ -12,7 +12,8 @@ from logbook.helpers import get_iterator_next_method from logbook.concurrency import ( thread_get_ident, greenlet_get_ident, thread_local, greenlet_local, - ThreadLock, GreenletRLock, is_gevent_enabled) + ThreadLock, GreenletRLock, is_gevent_enabled, ContextVar, context_get_ident, + is_context_enabled) _missing = object() _MAX_CONTEXT_OBJECT_CACHE = 256 @@ -67,6 +68,14 @@ """Pops the stacked object from the greenlet stack.""" raise NotImplementedError() + def push_context(self): + """Pushes the stacked object to the context stack.""" + raise NotImplementedError() + + def pop_context(self): + """Pops the stacked object from the context stack.""" + raise NotImplementedError() + def push_thread(self): """Pushes the stacked object to the thread stack.""" raise NotImplementedError() @@ -101,6 +110,13 @@ execute code while the object is bound to the greenlet. """ return _cls(self, self.push_greenlet, self.pop_greenlet) + + def contextbound(self, _cls=_StackBound): + """Can be used in combination with the `with` statement to + execute code while the object is bound to the concurrent + context. + """ + return _cls(self, self.push_context, self.pop_context) def threadbound(self, _cls=_StackBound): """Can be used in combination with the `with` statement to @@ -126,6 +142,7 @@ self._thread_context = thread_local() self._greenlet_context_lock = GreenletRLock() self._greenlet_context = greenlet_local() + self._context_stack = ContextVar('stack') self._cache = {} self._stackop = get_iterator_next_method(count()) @@ -134,15 +151,28 @@ application and context cache. """ use_gevent = is_gevent_enabled() - tid = greenlet_get_ident() if use_gevent else thread_get_ident() + use_context = is_context_enabled() + + if use_gevent: + tid = greenlet_get_ident() + elif use_context: + tid = context_get_ident() + else: + tid = thread_get_ident() + objects = self._cache.get(tid) if objects is None: if len(self._cache) > _MAX_CONTEXT_OBJECT_CACHE: self._cache.clear() objects = self._global[:] objects.extend(getattr(self._thread_context, 'stack', ())) + if use_gevent: objects.extend(getattr(self._greenlet_context, 'stack', ())) + + if use_context: + objects.extend(self._context_stack.get([])) + objects.sort(reverse=True) objects = [x[1] for x in objects] self._cache[tid] = objects @@ -173,6 +203,22 @@ finally: self._greenlet_context_lock.release() + def push_context(self, obj): + self._cache.pop(context_get_ident(), None) + item = (self._stackop(), obj) + stack = self._context_stack.get(None) + if stack is None: + stack = [item] + self._context_stack.set(stack) + else: + stack.append(item) + + def pop_context(self): + self._cache.pop(context_get_ident(), None) + stack = self._context_stack.get(None) + assert stack, 'no objects on stack' + return stack.pop()[1] + def push_thread(self, obj): self._thread_context_lock.acquire() try: diff --git a/logbook/_speedups.pyx b/logbook/_speedups.pyx index 02dbc3e..8e1d216 100644 --- a/logbook/_speedups.pyx +++ b/logbook/_speedups.pyx @@ -1,4 +1,5 @@ # -*- coding: utf-8 -*- +# cython: language_level=2 """ logbook._speedups ~~~~~~~~~~~~~~~~~ @@ -9,17 +10,17 @@ :license: BSD, see LICENSE for more details. """ -import platform + from logbook.concurrency import (is_gevent_enabled, thread_get_ident, greenlet_get_ident, thread_local, - GreenletRLock, greenlet_local) + GreenletRLock, greenlet_local, ContextVar, context_get_ident, is_context_enabled) from cpython.dict cimport PyDict_Clear, PyDict_SetItem -from cpython.list cimport PyList_New, PyList_Append, PyList_Sort, \ - PyList_SET_ITEM, PyList_GET_SIZE +from cpython.list cimport PyList_Append, PyList_Sort, PyList_GET_SIZE + from cpython.pythread cimport PyThread_type_lock, PyThread_allocate_lock, \ PyThread_release_lock, PyThread_acquire_lock, WAIT_LOCK -cdef object _missing = object() +_missing = object() cdef enum: _MAX_CONTEXT_OBJECT_CACHE = 256 @@ -40,7 +41,7 @@ def __get__(self, obj, type): if obj is None: return self - rv = getattr3(obj, self._name, _missing) + rv = getattr(obj, self._name, _missing) if rv is not _missing and rv != self.fallback: return rv if obj.group is None: @@ -96,9 +97,16 @@ cdef class StackedObject: - """Baseclass for all objects that provide stack manipulation + """Base class for all objects that provide stack manipulation operations. """ + cpdef push_context(self): + """Pushes the stacked object to the asyncio (via contextvar) stack.""" + raise NotImplementedError() + + cpdef pop_context(self): + """Pops the stacked object from the asyncio (via contextvar) stack.""" + raise NotImplementedError() cpdef push_greenlet(self): """Pushes the stacked object to the greenlet stack.""" @@ -154,6 +162,12 @@ execute code while the object is bound to the application. """ return _StackBound(self, self.push_application, self.pop_application) + + cpdef contextbound(self): + """Can be used in combination with the `with` statement to + execute code while the object is bound to the asyncio context. + """ + return _StackBound(self, self.push_context, self.pop_context) cdef class ContextStackManager: @@ -162,6 +176,7 @@ cdef object _thread_context cdef object _greenlet_context_lock cdef object _greenlet_context + cdef object _context_stack cdef dict _cache cdef int _stackcnt @@ -171,6 +186,7 @@ self._thread_context = thread_local() self._greenlet_context_lock = GreenletRLock() self._greenlet_context = greenlet_local() + self._context_stack = ContextVar('stack') self._cache = {} self._stackcnt = 0 @@ -180,15 +196,28 @@ cpdef iter_context_objects(self): use_gevent = is_gevent_enabled() - tid = greenlet_get_ident() if use_gevent else thread_get_ident() + use_context = is_context_enabled() + + if use_gevent: + tid = greenlet_get_ident() + elif use_context: + tid = context_get_ident() + else: + tid = thread_get_ident() + objects = self._cache.get(tid) if objects is None: if PyList_GET_SIZE(self._cache) > _MAX_CONTEXT_OBJECT_CACHE: PyDict_Clear(self._cache) objects = self._global[:] - objects.extend(getattr3(self._thread_context, 'stack', ())) + objects.extend(getattr(self._thread_context, 'stack', ())) + if use_gevent: - objects.extend(getattr3(self._greenlet_context, 'stack', ())) + objects.extend(getattr(self._greenlet_context, 'stack', ())) + + if use_context: + objects.extend(self._context_stack.get([])) + PyList_Sort(objects) objects = [(<_StackItem>x).val for x in objects] PyDict_SetItem(self._cache, tid, objects) @@ -199,7 +228,7 @@ try: self._cache.pop(greenlet_get_ident(), None) item = _StackItem(self._stackop(), obj) - stack = getattr3(self._greenlet_context, 'stack', None) + stack = getattr(self._greenlet_context, 'stack', None) if stack is None: self._greenlet_context.stack = [item] else: @@ -211,18 +240,35 @@ self._greenlet_context_lock.acquire() try: self._cache.pop(greenlet_get_ident(), None) - stack = getattr3(self._greenlet_context, 'stack', None) + stack = getattr(self._greenlet_context, 'stack', None) assert stack, 'no objects on stack' return (<_StackItem>stack.pop()).val finally: self._greenlet_context_lock.release() + cpdef push_context(self, obj): + self._cache.pop(context_get_ident(), None) + item = _StackItem(self._stackop(), obj) + stack = self._context_stack.get(None) + + if stack is None: + stack = [item] + self._context_stack.set(stack) + else: + PyList_Append(stack, item) + + cpdef pop_context(self): + self._cache.pop(context_get_ident(), None) + stack = self._context_stack.get(None) + assert stack, 'no objects on stack' + return (<_StackItem>stack.pop()).val + cpdef push_thread(self, obj): PyThread_acquire_lock(self._thread_context_lock, WAIT_LOCK) try: self._cache.pop(thread_get_ident(), None) item = _StackItem(self._stackop(), obj) - stack = getattr3(self._thread_context, 'stack', None) + stack = getattr(self._thread_context, 'stack', None) if stack is None: self._thread_context.stack = [item] else: @@ -234,7 +280,7 @@ PyThread_acquire_lock(self._thread_context_lock, WAIT_LOCK) try: self._cache.pop(thread_get_ident(), None) - stack = getattr3(self._thread_context, 'stack', None) + stack = getattr(self._thread_context, 'stack', None) assert stack, 'no objects on stack' return (<_StackItem>stack.pop()).val finally: diff --git a/logbook/base.py b/logbook/base.py index 9ad10b4..15fa831 100644 --- a/logbook/base.py +++ b/logbook/base.py @@ -23,9 +23,15 @@ parse_iso8601, string_types, to_safe_json, u, xrange) +_has_speedups = False try: + if os.environ.get('DISABLE_LOGBOOK_CEXT_AT_RUNTIME'): + raise ImportError("Speedups disabled via DISABLE_LOGBOOK_CEXT_AT_RUNTIME") + from logbook._speedups import ( _missing, group_reflected_property, ContextStackManager, StackedObject) + + _has_speedups = True except ImportError: from logbook._fallback import ( _missing, group_reflected_property, ContextStackManager, StackedObject) @@ -73,7 +79,7 @@ logbook.set_datetime_format("local") Other uses rely on your supplied :py:obj:`datetime_format`. - Using `pytz `_ for example:: + Using `pytz `_ for example:: from datetime import datetime import logbook @@ -206,6 +212,15 @@ popped = self.stack_manager.pop_greenlet() assert popped is self, 'popped unexpected object' + def push_context(self): + """Pushes the context object to the context stack.""" + self.stack_manager.push_context(self) + + def pop_context(self): + """Pops the context object from the stack.""" + popped = self.stack_manager.pop_context() + assert popped is self, 'popped unexpected object' + def push_thread(self): """Pushes the context object to the thread stack.""" self.stack_manager.push_thread(self) @@ -256,6 +271,14 @@ def pop_greenlet(self): for obj in reversed(self.objects): obj.pop_greenlet() + + def push_context(self): + for obj in self.objects: + obj.push_context() + + def pop_context(self): + for obj in reversed(self.objects): + obj.pop_context() class Processor(ContextObject): diff --git a/logbook/compat.py b/logbook/compat.py index b65ac00..602a11a 100644 --- a/logbook/compat.py +++ b/logbook/compat.py @@ -16,7 +16,7 @@ from datetime import date, datetime import logbook -from logbook.helpers import u, string_types, iteritems +from logbook.helpers import u, string_types, iteritems, collections_abc _epoch_ord = date(1970, 1, 1).toordinal() @@ -133,7 +133,7 @@ kwargs = None # Logging allows passing a mapping object, in which case args will be a mapping. - if isinstance(args, collections.Mapping): + if isinstance(args, collections_abc.Mapping): kwargs = args args = None record = LoggingCompatRecord(old_record.name, diff --git a/logbook/concurrency.py b/logbook/concurrency.py index f0d5373..cd0fcb6 100644 --- a/logbook/concurrency.py +++ b/logbook/concurrency.py @@ -164,3 +164,53 @@ return GreenletRLock() else: return ThreadRLock() + + +has_contextvars = True +try: + import contextvars +except ImportError: + has_contextvars = False + +if has_contextvars: + from contextvars import ContextVar + from itertools import count + + context_ident_counter = count() + context_ident = ContextVar('context_ident') + + def context_get_ident(): + try: + return context_ident.get() + except LookupError: + ident = 'context-%s' % next(context_ident_counter) + context_ident.set(ident) + return ident + + def is_context_enabled(): + try: + context_ident.get() + return True + except LookupError: + return False + +else: + class ContextVar(object): + def __init__(self, name): + self.name = name + self.local = thread_local() + + def set(self, value): + self.local = value + + def get(self, default=None): + if self.local is None: + return default + + return default + + def context_get_ident(): + return 1 + + def is_context_enabled(): + return False diff --git a/logbook/handlers.py b/logbook/handlers.py index 15a19b0..9c28a83 100644 --- a/logbook/handlers.py +++ b/logbook/handlers.py @@ -32,7 +32,7 @@ _missing, lookup_level, Flags, ContextObject, ContextStackManager, _datetime_factory) from logbook.helpers import ( - rename, b, _is_text_stream, is_unicode, PY2, zip, xrange, string_types, + rename, b, _is_text_stream, is_unicode, PY2, zip, xrange, string_types, collections_abc, integer_types, reraise, u, with_metaclass) from logbook.concurrency import new_fine_grained_lock @@ -1355,10 +1355,10 @@ # - tuple to be unpacked to variables keyfile and certfile. # - secure=() equivalent to secure=True for backwards compatibility. # - secure=False equivalent to secure=None to disable. - if isinstance(self.secure, collections.Mapping): + if isinstance(self.secure, collections_abc.Mapping): keyfile = self.secure.get('keyfile', None) certfile = self.secure.get('certfile', None) - elif isinstance(self.secure, collections.Iterable): + elif isinstance(self.secure, collections_abc.Iterable): # Allow empty tuple for backwards compatibility if len(self.secure) == 0: keyfile = certfile = None @@ -1381,7 +1381,7 @@ con.ehlo() # Allow credentials to be a tuple or dict. - if isinstance(self.credentials, collections.Mapping): + if isinstance(self.credentials, collections_abc.Mapping): credentials_args = () credentials_kwargs = self.credentials else: @@ -1900,6 +1900,10 @@ Handler.pop_thread(self) self.rollover() + def pop_context(self): + Handler.pop_context(self) + self.rollover() + def pop_greenlet(self): Handler.pop_greenlet(self) self.rollover() diff --git a/logbook/helpers.py b/logbook/helpers.py index d53bcf0..4ea693f 100644 --- a/logbook/helpers.py +++ b/logbook/helpers.py @@ -20,8 +20,10 @@ if PY2: import __builtin__ as _builtins + import collections as collections_abc else: import builtins as _builtins + import collections.abc as collections_abc try: import json diff --git a/logbook/more.py b/logbook/more.py index 10b06ca..3809cc0 100644 --- a/logbook/more.py +++ b/logbook/more.py @@ -327,7 +327,7 @@ .. versionchanged:: 1.0.0 Added Windows support if `colorama`_ is installed. - .. _`colorama`: https://pypi.python.org/pypi/colorama + .. _`colorama`: https://pypi.org/pypi/colorama """ _use_color = None @@ -383,7 +383,7 @@ .. versionchanged:: 1.0 Added Windows support if `colorama`_ is installed. - .. _`colorama`: https://pypi.python.org/pypi/colorama + .. _`colorama`: https://pypi.org/pypi/colorama """ def __init__(self, *args, **kwargs): StderrHandler.__init__(self, *args, **kwargs) @@ -471,6 +471,10 @@ def pop_thread(self): Handler.pop_thread(self) + self.flush() + + def pop_context(self): + Handler.pop_context(self) self.flush() def pop_greenlet(self): diff --git a/logbook/queues.py b/logbook/queues.py index 68ead9f..162615b 100644 --- a/logbook/queues.py +++ b/logbook/queues.py @@ -604,7 +604,10 @@ queue and sends it to a handler. Both queue and handler are taken from the passed :class:`ThreadedWrapperHandler`. """ - _sentinel = object() + class Command(object): + stop = object() + emit = object() + emit_batch = object() def __init__(self, wrapper_handler): self.wrapper_handler = wrapper_handler @@ -621,17 +624,23 @@ def stop(self): """Stops the task thread.""" if self.running: - self.wrapper_handler.queue.put_nowait(self._sentinel) + self.wrapper_handler.queue.put_nowait((self.Command.stop, )) self._thread.join() self._thread = None def _target(self): while 1: - record = self.wrapper_handler.queue.get() - if record is self._sentinel: + item = self.wrapper_handler.queue.get() + command, data = item[0], item[1:] + if command is self.Command.stop: self.running = False break - self.wrapper_handler.handler.handle(record) + elif command is self.Command.emit: + (record, ) = data + self.wrapper_handler.handler.emit(record) + elif command is self.Command.emit_batch: + record, reason = data + self.wrapper_handler.handler.emit_batch(record, reason) class ThreadedWrapperHandler(WrapperHandler): @@ -663,8 +672,17 @@ self.handler.close() def emit(self, record): - try: - self.queue.put_nowait(record) + item = (TWHThreadController.Command.emit, record) + try: + self.queue.put_nowait(item) + except Full: + # silently drop + pass + + def emit_batch(self, records, reason): + item = (TWHThreadController.Command.emit_batch, records, reason) + try: + self.queue.put_nowait(item) except Full: # silently drop pass diff --git a/scripts/test_setup.py b/scripts/test_setup.py index 2ebd976..f7b62c2 100644 --- a/scripts/test_setup.py +++ b/scripts/test_setup.py @@ -1,5 +1,5 @@ #! /usr/bin/python -import pip +from pip._internal import main as pip_main import sys if __name__ == '__main__': @@ -14,5 +14,5 @@ ] print("Setting up dependencies...") - result = pip.main(["install"] + deps) + result = pip_main(["install"] + deps) sys.exit(result) diff --git a/tests/conftest.py b/tests/conftest.py index 1882116..0a12dd5 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -1,3 +1,5 @@ +import sys + import logbook import pytest @@ -106,3 +108,10 @@ @request.addfinalizer def fin(): _disable_gevent() + + +def pytest_ignore_collect(path, config): + if 'test_asyncio.py' in path.basename and (sys.version_info.major < 3 or sys.version_info.minor < 5): + return True + + return False diff --git a/tests/test_asyncio.py b/tests/test_asyncio.py new file mode 100644 index 0000000..469554b --- /dev/null +++ b/tests/test_asyncio.py @@ -0,0 +1,27 @@ +import pytest +import logbook +import asyncio +from logbook.concurrency import has_contextvars + +ITERATIONS = 100 + + +@pytest.mark.skipif(not has_contextvars, reason="Contexvars not available") +def test_asyncio_context_management(logger): + h1 = logbook.TestHandler() + h2 = logbook.TestHandler() + + async def task(handler, msg): + for _ in range(ITERATIONS): + with handler.contextbound(): + logger.info(msg) + + await asyncio.sleep(0) # allow for context switch + + asyncio.get_event_loop().run_until_complete(asyncio.gather(task(h1, 'task1'), task(h2, 'task2'))) + + assert len(h1.records) == ITERATIONS + assert all(['task1' == r.msg for r in h1.records]) + + assert len(h2.records) == ITERATIONS + assert all(['task2' == r.msg for r in h2.records]) diff --git a/tests/test_queues.py b/tests/test_queues.py index 80ce040..63bf015 100644 --- a/tests/test_queues.py +++ b/tests/test_queues.py @@ -89,9 +89,24 @@ assert test_handler.has_warning('Hello World') +class BatchTestHandler(logbook.TestHandler): + def __init__(self, *args, **kwargs): + super(BatchTestHandler, self).__init__(*args, **kwargs) + self.batches = [] + + def emit(self, record): + super(BatchTestHandler, self).emit(record) + self.batches.append([record]) + + def emit_batch(self, records, reason): + for record in records: + super(BatchTestHandler, self).emit(record) + self.batches.append(records) + + def test_threaded_wrapper_handler(logger): from logbook.queues import ThreadedWrapperHandler - test_handler = logbook.TestHandler() + test_handler = BatchTestHandler() with ThreadedWrapperHandler(test_handler) as handler: logger.warn('Just testing') logger.error('More testing') @@ -100,6 +115,50 @@ handler.close() assert (not handler.controller.running) + assert len(test_handler.records) == 2 + assert len(test_handler.batches) == 2 + assert all((len(records) == 1 for records in test_handler.batches)) + assert test_handler.has_warning('Just testing') + assert test_handler.has_error('More testing') + + +def test_threaded_wrapper_handler_emit(): + from logbook.queues import ThreadedWrapperHandler + test_handler = BatchTestHandler() + with ThreadedWrapperHandler(test_handler) as handler: + lr = logbook.LogRecord('Test Logger', logbook.WARNING, 'Just testing') + test_handler.emit(lr) + lr = logbook.LogRecord('Test Logger', logbook.ERROR, 'More testing') + test_handler.emit(lr) + + # give it some time to sync up + handler.close() + + assert (not handler.controller.running) + assert len(test_handler.records) == 2 + assert len(test_handler.batches) == 2 + assert all((len(records) == 1 for records in test_handler.batches)) + assert test_handler.has_warning('Just testing') + assert test_handler.has_error('More testing') + + +def test_threaded_wrapper_handler_emit_batched(): + from logbook.queues import ThreadedWrapperHandler + test_handler = BatchTestHandler() + with ThreadedWrapperHandler(test_handler) as handler: + test_handler.emit_batch([ + logbook.LogRecord('Test Logger', logbook.WARNING, 'Just testing'), + logbook.LogRecord('Test Logger', logbook.ERROR, 'More testing'), + ], 'group') + + # give it some time to sync up + handler.close() + + assert (not handler.controller.running) + assert len(test_handler.records) == 2 + assert len(test_handler.batches) == 1 + (records, ) = test_handler.batches + assert len(records) == 2 assert test_handler.has_warning('Just testing') assert test_handler.has_error('More testing') @@ -164,10 +223,10 @@ import redis from logbook.queues import RedisHandler - KEY = 'redis' + KEY = 'redis-{}'.format(os.getpid()) FIELDS = ['message', 'host'] r = redis.Redis(decode_responses=True) - redis_handler = RedisHandler(level=logbook.INFO, bubble=True) + redis_handler = RedisHandler(key=KEY, level=logbook.INFO, bubble=True) # We don't want output for the tests, so we can wrap everything in a # NullHandler null_handler = logbook.NullHandler() @@ -185,7 +244,7 @@ assert message.find(LETTERS) # Change the key of the handler and check on redis - KEY = 'test_another_key' + KEY = 'test_another_key-{}'.format(os.getpid()) redis_handler.key = KEY with null_handler.applicationbound(): @@ -234,7 +293,8 @@ from logbook.queues import RedisHandler null_handler = logbook.NullHandler() - redis_handler = RedisHandler(key='lpushed', push_method='lpush', + KEY = 'lpushed-'.format(os.getpid()) + redis_handler = RedisHandler(key=KEY, push_method='lpush', level=logbook.INFO, bubble=True) with null_handler.applicationbound(): @@ -245,10 +305,10 @@ time.sleep(1.5) r = redis.Redis(decode_responses=True) - logs = r.lrange('lpushed', 0, -1) + logs = r.lrange(KEY, 0, -1) assert logs assert "new item" in logs[0] - r.delete('lpushed') + r.delete(KEY) @require_module('redis') @@ -261,7 +321,8 @@ from logbook.queues import RedisHandler null_handler = logbook.NullHandler() - redis_handler = RedisHandler(key='rpushed', push_method='rpush', + KEY = 'rpushed-' + str(os.getpid()) + redis_handler = RedisHandler(key=KEY, push_method='rpush', level=logbook.INFO, bubble=True) with null_handler.applicationbound(): @@ -272,10 +333,10 @@ time.sleep(1.5) r = redis.Redis(decode_responses=True) - logs = r.lrange('rpushed', 0, -1) + logs = r.lrange(KEY, 0, -1) assert logs assert "old item" in logs[0] - r.delete('rpushed') + r.delete(KEY) @pytest.fixture diff --git a/tests/test_syslog_handler.py b/tests/test_syslog_handler.py index d19d3f2..99447ef 100644 --- a/tests/test_syslog_handler.py +++ b/tests/test_syslog_handler.py @@ -4,66 +4,68 @@ from contextlib import closing import logbook -from logbook.helpers import u - import pytest -unix_socket = "/tmp/__unixsock_logbook.test" +UNIX_SOCKET = "/tmp/__unixsock_logbook.test" -to_test = [ +DELIMITERS = { + socket.AF_INET: '\n' +} + +TO_TEST = [ (socket.AF_INET, socket.SOCK_DGRAM, ('127.0.0.1', 0)), (socket.AF_INET, socket.SOCK_STREAM, ('127.0.0.1', 0)), ] -if hasattr(socket, 'AF_UNIX'): - to_test.append((socket.AF_UNIX, socket.SOCK_DGRAM, unix_socket)) + +UNIX_SOCKET_AVAILABLE = hasattr(socket, 'AF_UNIX') + +if UNIX_SOCKET_AVAILABLE: + DELIMITERS[socket.AF_UNIX] = '\x00' + TO_TEST.append((socket.AF_UNIX, socket.SOCK_DGRAM, UNIX_SOCKET)) + @pytest.mark.usefixtures("unix_sock_path") -@pytest.mark.parametrize("sock_family,socktype,address", to_test) -def test_syslog_handler(logger, activation_strategy, - sock_family, socktype, address): - delimiter = {socket.AF_UNIX: '\x00', - socket.AF_INET: '\n'}[sock_family] +@pytest.mark.parametrize("sock_family,socktype,address", TO_TEST) +@pytest.mark.parametrize("app_name", [None, 'Testing']) +def test_syslog_handler(logger, activation_strategy, sock_family, socktype, address, app_name): + delimiter = DELIMITERS[sock_family] with closing(socket.socket(sock_family, socktype)) as inc: inc.bind(address) + if socktype == socket.SOCK_STREAM: inc.listen(0) + inc.settimeout(1) - for app_name in [None, 'Testing']: - if sock_family == socket.AF_UNIX: - expected = (r'^<12>%stestlogger: Syslog is weird%s$' % - (app_name + ':' if app_name else '', - delimiter)) - else: - expected = (r'^<12>1 \d{4}-\d\d-\d\dT\d\d:\d\d:\d\d(\.\d+)?Z %s %s %d ' - '- - %sSyslog is weird%s$' % - (socket.gethostname(), - app_name if app_name else 'testlogger', - os.getpid(), 'testlogger: ' if app_name else '', - delimiter)) - handler = logbook.SyslogHandler(app_name, inc.getsockname(), - socktype=socktype) - with activation_strategy(handler): - logger.warn('Syslog is weird') - try: - if socktype == socket.SOCK_STREAM: - with closing(inc.accept()[0]) as inc2: - rv = inc2.recv(1024) - else: - rv = inc.recvfrom(1024)[0] - except socket.error: - assert False, 'got timeout on socket' - rv = rv.decode('utf-8') - assert re.match(expected, rv), \ - 'expected {}, got {}'.format(expected, rv) + if UNIX_SOCKET_AVAILABLE and sock_family == socket.AF_UNIX: + expected = (r'^<12>%stestlogger: Syslog is weird%s$' % (app_name + ':' if app_name else '', delimiter)) + else: + expected = (r'^<12>1 \d{4}-\d\d-\d\dT\d\d:\d\d:\d\d(\.\d+)?Z %s %s %d - - %sSyslog is weird%s$' % ( + socket.gethostname(), + app_name if app_name else 'testlogger', + os.getpid(), 'testlogger: ' if app_name else '', + delimiter)) + + handler = logbook.SyslogHandler(app_name, inc.getsockname(), socktype=socktype) + + with activation_strategy(handler): + logger.warn('Syslog is weird') + + if socktype == socket.SOCK_STREAM: + with closing(inc.accept()[0]) as inc2: + rv = inc2.recv(1024) + else: + rv = inc.recvfrom(1024)[0] + + rv = rv.decode('utf-8') + assert re.match(expected, rv), \ + 'expected {}, got {}'.format(expected, rv) @pytest.fixture -def unix_sock_path(request): - returned = unix_socket - - @request.addfinalizer - def cleanup(): - if os.path.exists(returned): - os.unlink(returned) - return returned +def unix_sock_path(): + try: + yield UNIX_SOCKET + finally: + if os.path.exists(UNIX_SOCKET): + os.unlink(UNIX_SOCKET) diff --git a/tox.ini b/tox.ini index ea70112..7c21509 100644 --- a/tox.ini +++ b/tox.ini @@ -1,35 +1,32 @@ [tox] -envlist=py27,py34,py35,py36,pypy,docs -skipsdist=True +envlist = py{27,35,36,37}{,-speedups},pypy,py37-docs +skipsdist = True [testenv] -whitelist_externals= - rm -deps= - py{27}: mock - pytest - Cython -changedir={toxinidir} -commands= - {envbindir}/cython logbook/_speedups.pyx - {envpython} {toxinidir}/setup.py develop - {envpython} {toxinidir}/scripts/test_setup.py - py.test {toxinidir}/tests - rm -f {toxinidir}/logbook/_speedups.\{so,c\} +whitelist_externals = + rm +deps = + py{27}: mock + pytest + speedups: Cython +setenv = + !speedups: DISABLE_LOGBOOK_CEXT=1 + !speedups: DISABLE_LOGBOOK_CEXT_AT_RUNTIME=1 +changedir = {toxinidir} +commands = + {envpython} -m pip install -e {toxinidir}[all] -[testenv:pypy] -deps= - mock - pytest -commands= - {envpython} {toxinidir}/setup.py develop - {envpython} {toxinidir}/scripts/test_setup.py - py.test {toxinidir}/tests + # Make sure that speedups are available/not available, as needed. + speedups: {envpython} -c "from logbook.base import _has_speedups; exit(0 if _has_speedups else 1)" + !speedups: {envpython} -c "from logbook.base import _has_speedups; exit(1 if _has_speedups else 0)" -[testenv:docs] -deps= - Sphinx==1.1.3 -changedir=docs -commands= - sphinx-build -W -b html . _build/html - sphinx-build -W -b linkcheck . _build/linkcheck + {envpython} {toxinidir}/scripts/test_setup.py + py.test {toxinidir}/tests + +[testenv:py37-docs] +deps = + Sphinx>=1.3 +changedir = docs +commands = + sphinx-build -W -b html . _build/html + sphinx-build -W -b linkcheck . _build/linkcheck