From 749c18b8b3b341f120bcf6648bc2ceb82191af9a Mon Sep 17 00:00:00 2001 From: Itamar Turner-Trauring Date: Sun, 18 Jun 2017 11:56:58 -0400 Subject: [PATCH 1/5] Move logging tests somewhere more reasonable. --- crochet/tests/test_logging.py | 59 +++++++++++++++++++++++++++++++++++ crochet/tests/test_setup.py | 51 ------------------------------ 2 files changed, 59 insertions(+), 51 deletions(-) create mode 100644 crochet/tests/test_logging.py diff --git a/crochet/tests/test_logging.py b/crochet/tests/test_logging.py new file mode 100644 index 0000000..e033ef4 --- /dev/null +++ b/crochet/tests/test_logging.py @@ -0,0 +1,59 @@ +"""Tests for the logging bridge.""" + +from __future__ import absolute_import + +from unittest import TestCase +import threading + +from twisted.python import threadable + +from .._eventloop import ThreadLogObserver + + +class ThreadLogObserverTest(TestCase): + """ + Tests for ThreadLogObserver. + """ + def test_stop(self): + """ + ThreadLogObserver.stop() stops the thread started in __init__. + """ + threadLog = ThreadLogObserver(None) + self.assertTrue(threadLog._thread.is_alive()) + threadLog.stop() + threadLog._thread.join() + self.assertFalse(threadLog._thread.is_alive()) + + def test_emit(self): + """ + ThreadLogObserver.emit runs the wrapped observer's in its thread, with + the given message. + """ + messages = [] + def observer(msg): + messages.append((threading.current_thread().ident, msg)) + + threadLog = ThreadLogObserver(observer) + ident = threadLog._thread.ident + msg1 = {} + msg2 = {"a": "b"} + threadLog(msg1) + threadLog(msg2) + threadLog.stop() + # Wait for writing to finish: + threadLog._thread.join() + self.assertEqual(messages, [(ident, msg1), (ident, msg2)]) + + + def test_ioThreadUnchanged(self): + """ + ThreadLogObserver does not change the Twisted I/O thread (which is + supposed to match the thread the main reactor is running in.) + """ + threadLog = ThreadLogObserver(None) + threadLog.stop() + threadLog._thread.join() + self.assertIn(threadable.ioThread, + # Either reactor was never run, or run in thread running + # the tests: + (None, threading.current_thread().ident)) diff --git a/crochet/tests/test_setup.py b/crochet/tests/test_setup.py index f60f99e..5bc7850 100644 --- a/crochet/tests/test_setup.py +++ b/crochet/tests/test_setup.py @@ -14,7 +14,6 @@ from twisted.python.log import PythonLoggingObserver from twisted.python import log from twisted.python.runtime import platform -from twisted.python import threadable from twisted.internet.task import Clock from .._eventloop import EventLoop, ThreadLogObserver, _store @@ -265,56 +264,6 @@ def test_non_posix(self): self.assertFalse(reactor.getDelayedCalls()) -class ThreadLogObserverTest(TestCase): - """ - Tests for ThreadLogObserver. - """ - def test_stop(self): - """ - ThreadLogObserver.stop() stops the thread started in __init__. - """ - threadLog = ThreadLogObserver(None) - self.assertTrue(threadLog._thread.is_alive()) - threadLog.stop() - threadLog._thread.join() - self.assertFalse(threadLog._thread.is_alive()) - - def test_emit(self): - """ - ThreadLogObserver.emit runs the wrapped observer's in its thread, with - the given message. - """ - messages = [] - def observer(msg): - messages.append((threading.current_thread().ident, msg)) - - threadLog = ThreadLogObserver(observer) - ident = threadLog._thread.ident - msg1 = {} - msg2 = {"a": "b"} - threadLog(msg1) - threadLog(msg2) - threadLog.stop() - # Wait for writing to finish: - threadLog._thread.join() - self.assertEqual(messages, [(ident, msg1), (ident, msg2)]) - - - def test_ioThreadUnchanged(self): - """ - ThreadLogObserver does not change the Twisted I/O thread (which is - supposed to match the thread the main reactor is running in.) - """ - threadLog = ThreadLogObserver(None) - threadLog.stop() - threadLog._thread.join() - self.assertIn(threadable.ioThread, - # Either reactor was never run, or run in thread running - # the tests: - (None, threading.current_thread().ident)) - - - class ReactorImportTests(TestCase): """ Tests for when the reactor gets imported. From f42ac6dee102ad73f328817dcba49fab3e9c7d73 Mon Sep 17 00:00:00 2001 From: Itamar Turner-Trauring Date: Sun, 18 Jun 2017 12:06:09 -0400 Subject: [PATCH 2/5] Test for unhandled errors coming out of destination logging infrastructure. --- crochet/tests/test_logging.py | 31 +++++++++++++++++++++++++++++-- 1 file changed, 29 insertions(+), 2 deletions(-) diff --git a/crochet/tests/test_logging.py b/crochet/tests/test_logging.py index e033ef4..9dc351b 100644 --- a/crochet/tests/test_logging.py +++ b/crochet/tests/test_logging.py @@ -2,7 +2,7 @@ from __future__ import absolute_import -from unittest import TestCase +from twisted.trial.unittest import SynchronousTestCase import threading from twisted.python import threadable @@ -10,9 +10,12 @@ from .._eventloop import ThreadLogObserver -class ThreadLogObserverTest(TestCase): +class ThreadLogObserverTest(SynchronousTestCase): """ Tests for ThreadLogObserver. + + We use Twisted's SyncTestCase to ensure that unhandled logged errors get + reported as errors, in particular for test_error. """ def test_stop(self): """ @@ -44,6 +47,30 @@ def observer(msg): threadLog._thread.join() self.assertEqual(messages, [(ident, msg1), (ident, msg2)]) + def test_errors(self): + """ + ThreadLogObserver.emit catches and silently drops exceptions from its + observer. + """ + messages = [] + counter = [] + def observer(msg): + counter.append(1) + if len(counter) == 2: + raise RuntimeError("ono a bug") + messages.append(msg) + + threadLog = ThreadLogObserver(observer) + msg1 = {"m": "1"} + msg2 = {"m": "2"} + msg3 = {"m": "3"} + threadLog(msg1) + threadLog(msg2) + threadLog(msg3) + threadLog.stop() + # Wait for writing to finish: + threadLog._thread.join() + self.assertEqual(messages, [msg1, msg3]) def test_ioThreadUnchanged(self): """ From 8bba614f9f3d64c3741a43f48607e8ff6c5b50a1 Mon Sep 17 00:00:00 2001 From: Itamar Turner-Trauring Date: Sun, 18 Jun 2017 12:09:14 -0400 Subject: [PATCH 3/5] Catch errors from underlying logging system. --- crochet/_eventloop.py | 10 +++++++++- 1 file changed, 9 insertions(+), 1 deletion(-) diff --git a/crochet/_eventloop.py b/crochet/_eventloop.py index d6f7baa..9980e99 100644 --- a/crochet/_eventloop.py +++ b/crochet/_eventloop.py @@ -298,7 +298,15 @@ def __call__(self, msg): """ A log observer that writes to a queue. """ - self._logWritingReactor.callFromThread(self._observer, msg) + def log(): + try: + self._observer(msg) + except: + # Lower-level logging system blew up, nothing we can do, so + # just drop on the floor. + pass + + self._logWritingReactor.callFromThread(log) class EventLoop(object): From de0f5fb031a389fbc888a17fb3543f33149e9f0c Mon Sep 17 00:00:00 2001 From: Itamar Turner-Trauring Date: Sun, 18 Jun 2017 16:16:07 -0400 Subject: [PATCH 4/5] Increase minimum supported version since we now need SynchronousTestCase. --- .travis.yml | 10 ++++++---- 1 file changed, 6 insertions(+), 4 deletions(-) diff --git a/.travis.yml b/.travis.yml index c080557..3777fa6 100644 --- a/.travis.yml +++ b/.travis.yml @@ -1,14 +1,16 @@ language: python env: - - TWISTED=Twisted==15.0 RUNTESTS=trial - - TWISTED=Twisted RUNTESTS=trial + # Oldest supported version: + - TWISTED=Twisted==16.0 + # Latest Twisted: + - TWISTED=Twisted python: - 2.7 - 3.4 - 3.5 - - 3.6-dev + - 3.6 - pypy install: @@ -17,7 +19,7 @@ install: - python setup.py -q install script: - - $RUNTESTS crochet.tests + - trial crochet.tests - pyflakes crochet notifications: From 0a709156fed117002d8ddfbedbb7c6a18d8044bc Mon Sep 17 00:00:00 2001 From: Itamar Turner-Trauring Date: Sun, 18 Jun 2017 17:57:30 -0400 Subject: [PATCH 5/5] News entry. --- docs/news.rst | 12 ++++++++++++ 1 file changed, 12 insertions(+) diff --git a/docs/news.rst b/docs/news.rst index 7d97d31..1ce83fc 100644 --- a/docs/news.rst +++ b/docs/news.rst @@ -1,6 +1,18 @@ What's New ========== +1.7.0 +^^^^^ + +Bug fixes: + +* If the Python `logging.Handler` throws an exception Crochet no longer goes into a death spiral. + Thanks to Michael Schlenker for the bug report. + +Removed features: + +* Versions of Twisted < 16.0 are no longer supported (i.e. no longer tested in CI.) + 1.6.0 ^^^^^