From 91753cae5962a56ce0440b06891f1040ba7582e9 Mon Sep 17 00:00:00 2001 From: Richard van der Hoff <1389908+richvdh@users.noreply.github.com> Date: Wed, 3 Jul 2019 09:31:27 +0100 Subject: [PATCH] Fix a number of "Starting txn from sentinel context" warnings (#5605) Fixes #5602, #5603 --- changelog.d/5605.bugfix | 1 + synapse/handlers/account_validity.py | 10 +++++++++- synapse/storage/events.py | 9 ++++++++- synapse/storage/registration.py | 13 ++++++++++--- synapse/util/__init__.py | 8 +++++++- 5 files changed, 35 insertions(+), 6 deletions(-) create mode 100644 changelog.d/5605.bugfix diff --git a/changelog.d/5605.bugfix b/changelog.d/5605.bugfix new file mode 100644 index 000000000..4995ba9f6 --- /dev/null +++ b/changelog.d/5605.bugfix @@ -0,0 +1 @@ +Fix a number of "Starting txn from sentinel context" warnings. diff --git a/synapse/handlers/account_validity.py b/synapse/handlers/account_validity.py index 0719da3ab..edb48054a 100644 --- a/synapse/handlers/account_validity.py +++ b/synapse/handlers/account_validity.py @@ -22,6 +22,7 @@ from email.mime.text import MIMEText from twisted.internet import defer from synapse.api.errors import StoreError +from synapse.metrics.background_process_metrics import run_as_background_process from synapse.types import UserID from synapse.util import stringutils from synapse.util.logcontext import make_deferred_yieldable @@ -67,7 +68,14 @@ class AccountValidityHandler(object): ) # Check the renewal emails to send and send them every 30min. - self.clock.looping_call(self.send_renewal_emails, 30 * 60 * 1000) + def send_emails(): + # run as a background process to make sure that the database transactions + # have a logcontext to report to + return run_as_background_process( + "send_renewals", self.send_renewal_emails + ) + + self.clock.looping_call(send_emails, 30 * 60 * 1000) @defer.inlineCallbacks def send_renewal_emails(self): diff --git a/synapse/storage/events.py b/synapse/storage/events.py index fefba39ea..86f848570 100644 --- a/synapse/storage/events.py +++ b/synapse/storage/events.py @@ -253,7 +253,14 @@ class EventsStore( ) # Read the extrems every 60 minutes - hs.get_clock().looping_call(self._read_forward_extremities, 60 * 60 * 1000) + def read_forward_extremities(): + # run as a background process to make sure that the database transactions + # have a logcontext to report to + return run_as_background_process( + "read_forward_extremities", self._read_forward_extremities + ) + + hs.get_clock().looping_call(read_forward_extremities, 60 * 60 * 1000) @defer.inlineCallbacks def _read_forward_extremities(self): diff --git a/synapse/storage/registration.py b/synapse/storage/registration.py index 983ce1329..13a3d5208 100644 --- a/synapse/storage/registration.py +++ b/synapse/storage/registration.py @@ -25,6 +25,7 @@ from twisted.internet import defer from synapse.api.constants import UserTypes from synapse.api.errors import Codes, StoreError, ThreepidValidationError +from synapse.metrics.background_process_metrics import run_as_background_process from synapse.storage import background_updates from synapse.storage._base import SQLBaseStore from synapse.types import UserID @@ -619,9 +620,15 @@ class RegistrationStore( ) # Create a background job for culling expired 3PID validity tokens - hs.get_clock().looping_call( - self.cull_expired_threepid_validation_tokens, THIRTY_MINUTES_IN_MS - ) + def start_cull(): + # run as a background process to make sure that the database transactions + # have a logcontext to report to + return run_as_background_process( + "cull_expired_threepid_validation_tokens", + self.cull_expired_threepid_validation_tokens, + ) + + hs.get_clock().looping_call(start_cull, THIRTY_MINUTES_IN_MS) @defer.inlineCallbacks def _backgroud_update_set_deactivated_flag(self, progress, batch_size): diff --git a/synapse/util/__init__.py b/synapse/util/__init__.py index dcc747cac..954e32fb2 100644 --- a/synapse/util/__init__.py +++ b/synapse/util/__init__.py @@ -62,7 +62,10 @@ class Clock(object): def looping_call(self, f, msec): """Call a function repeatedly. - Waits `msec` initially before calling `f` for the first time. + Waits `msec` initially before calling `f` for the first time. + + Note that the function will be called with no logcontext, so if it is anything + other than trivial, you probably want to wrap it in run_as_background_process. Args: f(function): The function to call repeatedly. @@ -77,6 +80,9 @@ class Clock(object): def call_later(self, delay, callback, *args, **kwargs): """Call something later + Note that the function will be called with no logcontext, so if it is anything + other than trivial, you probably want to wrap it in run_as_background_process. + Args: delay(float): How long to wait in seconds. callback(function): Function to call