Merge branch 'master' into develop

11 files changed, 62 insertions, 40 deletions

diff --git a/CHANGES.md b/CHANGES.md
index 41908f84be..482863c0e8 100644
--- a/CHANGES.md
+++ b/CHANGES.md
@@ -1,11 +1,20 @@
-Synapse 1.32.0rc1 (2021-04-13)
-==============================
+Synapse 1.32.0 (2021-04-20)
+===========================
 
 **Note:** This release requires Python 3.6+ and Postgres 9.6+ or SQLite 3.22+.
 
 This release removes the deprecated `GET /_synapse/admin/v1/users/<user_id>` admin API. Please use the [v2 API](https://github.com/matrix-org/synapse/blob/develop/docs/admin_api/user_admin_api.rst#query-user-account) instead, which has improved capabilities.
 
-This release requires Application Services to use type `m.login.application_services` when registering users via the `/_matrix/client/r0/register` endpoint to comply with the spec. Please ensure your Application Services are up to date.
+This release requires Application Services to use type `m.login.application_service` when registering users via the `/_matrix/client/r0/register` endpoint to comply with the spec. Please ensure your Application Services are up to date.
+
+Bugfixes
+--------
+
+- Fix the log lines of nested logging contexts. Broke in 1.32.0rc1. ([\#9829](https://github.com/matrix-org/synapse/issues/9829))
+
+
+Synapse 1.32.0rc1 (2021-04-13)
+==============================
 
 Features
 --------
diff --git a/UPGRADE.rst b/UPGRADE.rst
index eff976017d..dc87b84cad 100644
--- a/UPGRADE.rst
+++ b/UPGRADE.rst
@@ -111,6 +111,14 @@ upon attempting to use a valid renewal token more than once.
 Upgrading to v1.32.0
 ====================
 
+Dropping support for old Python, Postgres and SQLite versions
+-------------------------------------------------------------
+
+In line with our `deprecation policy <https://github.com/matrix-org/synapse/blob/release-v1.32.0/docs/deprecation_policy.md>`_,
+we've dropped support for Python 3.5 and PostgreSQL 9.5, as they are no longer supported upstream.
+
+This release of Synapse requires Python 3.6+ and PostgresSQL 9.6+ or SQLite 3.22+.
+
 Removal of old List Accounts Admin API
 --------------------------------------
 
@@ -121,6 +129,16 @@ has been available since Synapse 1.7.0 (2019-12-13), and is accessible under ``G
 
 The deprecation of the old endpoint was announced with Synapse 1.28.0 (released on 2021-02-25).
 
+Application Services must use type ``m.login.application_service`` when registering users
+-----------------------------------------------------------------------------------------
+
+In compliance with the
+`Application Service spec <https://matrix.org/docs/spec/application_service/r0.1.2#server-admin-style-permissions>`_,
+Application Services are now required to use the ``m.login.application_service`` type when registering users via the
+``/_matrix/client/r0/register`` endpoint. This behaviour was deprecated in Synapse v1.30.0.
+
+Please ensure your Application Services are up to date.
+
 Upgrading to v1.29.0
 ====================
 
diff --git a/debian/changelog b/debian/changelog
index 5d526316fc..83be4497ec 100644
--- a/debian/changelog
+++ b/debian/changelog
@@ -1,8 +1,12 @@
-matrix-synapse-py3 (1.31.0+nmu1) UNRELEASED; urgency=medium
+matrix-synapse-py3 (1.32.0) stable; urgency=medium
 
+  [ Dan Callahan ]
   * Skip tests when DEB_BUILD_OPTIONS contains "nocheck".
 
- -- Dan Callahan <danc@element.io>  Mon, 12 Apr 2021 13:07:36 +0000
+  [ Synapse Packaging team ]
+  * New synapse release 1.32.0.
+
+ -- Synapse Packaging team <packages@matrix.org>  Tue, 20 Apr 2021 14:28:39 +0100
 
 matrix-synapse-py3 (1.31.0) stable; urgency=medium
 
diff --git a/synapse/__init__.py b/synapse/__init__.py
index c2709c2ad4..7e97f5d995 100644
--- a/synapse/__init__.py
+++ b/synapse/__init__.py
@@ -47,7 +47,7 @@ try:
 except ImportError:
     pass
 
-__version__ = "1.32.0rc1"
+__version__ = "1.32.0"
 
 if bool(os.environ.get("SYNAPSE_TEST_PATCH_LOG_CONTEXTS", False)):
     # We import here so that we don't have to install a bunch of deps when
diff --git a/synapse/logging/context.py b/synapse/logging/context.py
index e78343f554..dbd7d3a33a 100644
--- a/synapse/logging/context.py
+++ b/synapse/logging/context.py
@@ -277,7 +277,7 @@ class LoggingContext:
 
     def __init__(
         self,
-        name: Optional[str] = None,
+        name: str,
         parent_context: "Optional[LoggingContext]" = None,
         request: Optional[ContextRequest] = None,
     ) -> None:
@@ -315,9 +315,7 @@ class LoggingContext:
             self.request = request
 
     def __str__(self) -> str:
-        if self.request:
-            return self.request.request_id
-        return "%s@%x" % (self.name, id(self))
+        return self.name
 
     @classmethod
     def current_context(cls) -> LoggingContextOrSentinel:
@@ -694,17 +692,13 @@ def nested_logging_context(suffix: str) -> LoggingContext:
             "Starting nested logging context from sentinel context: metrics will be lost"
         )
         parent_context = None
-        prefix = ""
-        request = None
     else:
         assert isinstance(curr_context, LoggingContext)
         parent_context = curr_context
-        prefix = str(parent_context.name)
-        request = parent_context.request
+    prefix = str(curr_context)
     return LoggingContext(
         prefix + "-" + suffix,
         parent_context=parent_context,
-        request=request,
     )
 
 
@@ -895,7 +889,7 @@ def defer_to_threadpool(reactor, threadpool, f, *args, **kwargs):
         parent_context = curr_context
 
     def g():
-        with LoggingContext(parent_context=parent_context):
+        with LoggingContext(str(curr_context), parent_context=parent_context):
             return f(*args, **kwargs)
 
     return make_deferred_yieldable(threads.deferToThreadPool(reactor, threadpool, g))
diff --git a/synapse/metrics/background_process_metrics.py b/synapse/metrics/background_process_metrics.py
index cbd0894e57..c56f0dd124 100644
--- a/synapse/metrics/background_process_metrics.py
+++ b/synapse/metrics/background_process_metrics.py
@@ -15,7 +15,7 @@
 import logging
 import threading
 from functools import wraps
-from typing import TYPE_CHECKING, Dict, Optional, Set, Union
+from typing import TYPE_CHECKING, Dict, Optional, Set
 
 from prometheus_client.core import REGISTRY, Counter, Gauge
 
@@ -198,7 +198,7 @@ def run_as_background_process(desc: str, func, *args, bg_start_span=True, **kwar
         _background_process_start_count.labels(desc).inc()
         _background_process_in_flight_count.labels(desc).inc()
 
-        with BackgroundProcessLoggingContext(desc, count) as context:
+        with BackgroundProcessLoggingContext("%s-%s" % (desc, count)) as context:
             try:
                 ctx = noop_context_manager()
                 if bg_start_span:
@@ -241,19 +241,12 @@ class BackgroundProcessLoggingContext(LoggingContext):
     processes.
     """
 
-    __slots__ = ["_id", "_proc"]
+    __slots__ = ["_proc"]
 
-    def __init__(self, name: str, id: Optional[Union[int, str]] = None):
+    def __init__(self, name: str):
         super().__init__(name)
-        self._id = id
-
         self._proc = _BackgroundProcess(name, self)
 
-    def __str__(self) -> str:
-        if self._id is not None:
-            return "%s-%s" % (self.name, self._id)
-        return "%s@%x" % (self.name, id(self))
-
     def start(self, rusage: "Optional[resource._RUsage]"):
         """Log context has started running (again)."""
 
diff --git a/synapse/replication/tcp/protocol.py b/synapse/replication/tcp/protocol.py
index 6860576e78..2df028f315 100644
--- a/synapse/replication/tcp/protocol.py
+++ b/synapse/replication/tcp/protocol.py
@@ -184,7 +184,7 @@ class BaseReplicationStreamProtocol(LineOnlyReceiver):
         # a logcontext which we use for processing incoming commands. We declare it as a
         # background process so that the CPU stats get reported to prometheus.
         self._logging_context = BackgroundProcessLoggingContext(
-            "replication-conn", self.conn_id
+            "replication-conn-%s" % (self.conn_id,)
         )
 
     def connectionMade(self):
diff --git a/synapse/util/metrics.py b/synapse/util/metrics.py
index 6ed7179e8c..6d14351bd2 100644
--- a/synapse/util/metrics.py
+++ b/synapse/util/metrics.py
@@ -104,7 +104,13 @@ class Measure:
         "start",
     ]
 
-    def __init__(self, clock, name):
+    def __init__(self, clock, name: str):
+        """
+        Args:
+            clock: A n object with a "time()" method, which returns the current
+                time in seconds.
+            name: The name of the metric to report.
+        """
         self.clock = clock
         self.name = name
         curr_context = current_context()
@@ -117,10 +123,8 @@ class Measure:
         else:
             assert isinstance(curr_context, LoggingContext)
             parent_context = curr_context
-        self._logging_context = LoggingContext(
-            "Measure[%s]" % (self.name,), parent_context
-        )
-        self.start = None
+        self._logging_context = LoggingContext(str(curr_context), parent_context)
+        self.start = None  # type: Optional[int]
 
     def __enter__(self) -> "Measure":
         if self.start is not None:
diff --git a/tests/logging/test_terse_json.py b/tests/logging/test_terse_json.py
index 6cddb95c30..1160716929 100644
--- a/tests/logging/test_terse_json.py
+++ b/tests/logging/test_terse_json.py
@@ -137,7 +137,7 @@ class TerseJsonTestCase(LoggerCleanupMixin, TestCase):
         ]
         self.assertCountEqual(log.keys(), expected_log_keys)
         self.assertEqual(log["log"], "Hello there, wally!")
-        self.assertTrue(log["request"].startswith("name@"))
+        self.assertEqual(log["request"], "name")
 
     def test_with_request_context(self):
         """
@@ -164,7 +164,9 @@ class TerseJsonTestCase(LoggerCleanupMixin, TestCase):
         # Also set the requester to ensure the processing works.
         request.requester = "@foo:test"
 
-        with LoggingContext(parent_context=request.logcontext):
+        with LoggingContext(
+            request.get_request_id(), parent_context=request.logcontext
+        ):
             logger.info("Hello there, %s!", "wally")
 
         log = self.get_log_line()
diff --git a/tests/test_federation.py b/tests/test_federation.py
index 0a3a996ec1..0ed8326f55 100644
--- a/tests/test_federation.py
+++ b/tests/test_federation.py
@@ -135,7 +135,7 @@ class MessageAcceptTests(unittest.HomeserverTestCase):
             }
         )
 
-        with LoggingContext():
+        with LoggingContext("test-context"):
             failure = self.get_failure(
                 self.handler.on_receive_pdu(
                     "test.serv", lying_event, sent_to_us_directly=True
diff --git a/tests/util/caches/test_descriptors.py b/tests/util/caches/test_descriptors.py
index 40cd98e2d8..178ac8a68c 100644
--- a/tests/util/caches/test_descriptors.py
+++ b/tests/util/caches/test_descriptors.py
@@ -230,8 +230,7 @@ class DescriptorTestCase(unittest.TestCase):
 
         @defer.inlineCallbacks
         def do_lookup():
-            with LoggingContext() as c1:
-                c1.name = "c1"
+            with LoggingContext("c1") as c1:
                 r = yield obj.fn(1)
                 self.assertEqual(current_context(), c1)
             return r
@@ -273,8 +272,7 @@ class DescriptorTestCase(unittest.TestCase):
 
         @defer.inlineCallbacks
         def do_lookup():
-            with LoggingContext() as c1:
-                c1.name = "c1"
+            with LoggingContext("c1") as c1:
                 try:
                     d = obj.fn(1)
                     self.assertEqual(