diff --git a/synapse/util/__init__.py b/synapse/util/__init__.py
index e57fb0e914..7ec5033ceb 100644
--- a/synapse/util/__init__.py
+++ b/synapse/util/__init__.py
@@ -37,6 +37,7 @@ class Clock(object):
def call_later(self, delay, callback):
current_context = LoggingContext.current_context()
+
def wrapped_callback():
LoggingContext.thread_local.current_context = current_context
callback()
diff --git a/synapse/util/async.py b/synapse/util/async.py
index 1219d927db..7dd3ec3a72 100644
--- a/synapse/util/async.py
+++ b/synapse/util/async.py
@@ -18,6 +18,7 @@ from twisted.internet import defer, reactor
from .logcontext import PreserveLoggingContext
+
@defer.inlineCallbacks
def sleep(seconds):
d = defer.Deferred()
@@ -25,6 +26,7 @@ def sleep(seconds):
with PreserveLoggingContext():
yield d
+
def run_on_reactor():
""" This will cause the rest of the function to be invoked upon the next
iteration of the main loop
diff --git a/synapse/util/distributor.py b/synapse/util/distributor.py
index eddbe5837f..701ccdb781 100644
--- a/synapse/util/distributor.py
+++ b/synapse/util/distributor.py
@@ -13,6 +13,8 @@
# See the License for the specific language governing permissions and
# limitations under the License.
+from synapse.util.logcontext import PreserveLoggingContext
+
from twisted.internet import defer
import logging
@@ -91,6 +93,7 @@ class Signal(object):
Each observer callable may return a Deferred."""
self.observers.append(observer)
+ @defer.inlineCallbacks
def fire(self, *args, **kwargs):
"""Invokes every callable in the observer list, passing in the args and
kwargs. Exceptions thrown by observers are logged but ignored. It is
@@ -98,22 +101,24 @@ class Signal(object):
Returns a Deferred that will complete when all the observers have
completed."""
- deferreds = []
- for observer in self.observers:
- d = defer.maybeDeferred(observer, *args, **kwargs)
-
- def eb(failure):
- logger.warning(
- "%s signal observer %s failed: %r",
- self.name, observer, failure,
- exc_info=(
- failure.type,
- failure.value,
- failure.getTracebackObject()))
- if not self.suppress_failures:
- raise failure
- deferreds.append(d.addErrback(eb))
-
- return defer.DeferredList(
- deferreds, fireOnOneErrback=not self.suppress_failures
- )
+ with PreserveLoggingContext():
+ deferreds = []
+ for observer in self.observers:
+ d = defer.maybeDeferred(observer, *args, **kwargs)
+
+ def eb(failure):
+ logger.warning(
+ "%s signal observer %s failed: %r",
+ self.name, observer, failure,
+ exc_info=(
+ failure.type,
+ failure.value,
+ failure.getTracebackObject()))
+ if not self.suppress_failures:
+ raise failure
+ deferreds.append(d.addErrback(eb))
+
+ result = yield defer.DeferredList(
+ deferreds, fireOnOneErrback=not self.suppress_failures
+ )
+ defer.returnValue(result)
diff --git a/synapse/util/logcontext.py b/synapse/util/logcontext.py
index 2f430a0f19..7d85018d97 100644
--- a/synapse/util/logcontext.py
+++ b/synapse/util/logcontext.py
@@ -1,6 +1,8 @@
import threading
import logging
+logger = logging.getLogger(__name__)
+
class LoggingContext(object):
"""Additional context for log formatting. Contexts are scoped within a
@@ -53,11 +55,14 @@ class LoggingContext(object):
None to avoid suppressing any exeptions that were thrown.
"""
if self.thread_local.current_context is not self:
- logging.error(
- "Current logging context %s is not the expected context %s",
- self.thread_local.current_context,
- self
- )
+ if self.thread_local.current_context is self.sentinel:
+ logger.debug("Expected logging context %s has been lost", self)
+ else:
+ logger.warn(
+ "Current logging context %s is not expected context %s",
+ self.thread_local.current_context,
+ self
+ )
self.thread_local.current_context = self.parent_context
self.parent_context = None
|
