Work around twisted.protocols.amp.TooLong error by reducing logging in some tests.

changelog.d/18736.misc

@@ -0,0 +1 @@
+Work around `twisted.protocols.amp.TooLong` error by reducing logging in some tests.

tests/replication/tcp/streams/test_typing.py

@@ -18,6 +18,7 @@
 # [This file includes modifications made by New Vector Limited]
 #
 #
+import logging
 from unittest.mock import Mock
 
 from synapse.handlers.typing import RoomMember, TypingWriterHandler
@@ -99,75 +100,86 @@ def test_reset(self) -> None:
         This is emulated by jumping the stream ahead, then reconnecting (which
         sends the proper position and RDATA).
         """
-        typing = self.hs.get_typing_handler()
-        assert isinstance(typing, TypingWriterHandler)
-
-        # Create a typing update before we reconnect so that there is a missing
-        # update to fetch.
-        typing._push_update(member=RoomMember(ROOM_ID, USER_ID), typing=True)
-
-        self.reconnect()
-
-        typing._push_update(member=RoomMember(ROOM_ID, USER_ID), typing=True)
-
-        self.reactor.advance(0)
-
-        # We should now see an attempt to connect to the master
-        request = self.handle_http_replication_attempt()
-        self.assert_request_is_get_repl_stream_updates(request, "typing")
-
-        self.mock_handler.on_rdata.assert_called_once()
-        stream_name, _, token, rdata_rows = self.mock_handler.on_rdata.call_args[0]
-        self.assertEqual(stream_name, "typing")
-        self.assertEqual(1, len(rdata_rows))
-        row: TypingStream.TypingStreamRow = rdata_rows[0]
-        self.assertEqual(ROOM_ID, row.room_id)
-        self.assertEqual([USER_ID], row.user_ids)
-
-        # Push the stream forward a bunch so it can be reset.
-        for i in range(100):
-            typing._push_update(
-                member=RoomMember(ROOM_ID, "@test%s:blue" % i), typing=True
+        # FIXME: Because huge RDATA log line is triggered in this test,
+        # trial breaks, sometimes (flakily) failing the test run.
+        # ref: https://github.com/twisted/twisted/issues/12482
+        # To remove this, we would need to fix the above issue and
+        # update, including in olddeps (so several years' wait).
+        server_logger = logging.getLogger("tests.server")
+        server_logger_was_disabled = server_logger.disabled
+        server_logger.disabled = True
+        try:
+            typing = self.hs.get_typing_handler()
+            assert isinstance(typing, TypingWriterHandler)
+
+            # Create a typing update before we reconnect so that there is a missing
+            # update to fetch.
+            typing._push_update(member=RoomMember(ROOM_ID, USER_ID), typing=True)
+
+            self.reconnect()
+
+            typing._push_update(member=RoomMember(ROOM_ID, USER_ID), typing=True)
+
+            self.reactor.advance(0)
+
+            # We should now see an attempt to connect to the master
+            request = self.handle_http_replication_attempt()
+            self.assert_request_is_get_repl_stream_updates(request, "typing")
+
+            self.mock_handler.on_rdata.assert_called_once()
+            stream_name, _, token, rdata_rows = self.mock_handler.on_rdata.call_args[0]
+            self.assertEqual(stream_name, "typing")
+            self.assertEqual(1, len(rdata_rows))
+            row: TypingStream.TypingStreamRow = rdata_rows[0]
+            self.assertEqual(ROOM_ID, row.room_id)
+            self.assertEqual([USER_ID], row.user_ids)
+
+            # Push the stream forward a bunch so it can be reset.
+            for i in range(100):
+                typing._push_update(
+                    member=RoomMember(ROOM_ID, "@test%s:blue" % i), typing=True
+                )
+            self.reactor.advance(0)
+
+            # Disconnect.
+            self.disconnect()
+
+            # Reset the typing handler
+            self.hs.get_replication_streams()["typing"].last_token = 0
+            self.hs.get_replication_command_handler()._streams["typing"].last_token = 0
+            typing._latest_room_serial = 0
+            typing._typing_stream_change_cache = StreamChangeCache(
+                name="TypingStreamChangeCache",
+                server_name=self.hs.hostname,
+                current_stream_pos=typing._latest_room_serial,
             )
-        self.reactor.advance(0)
-
-        # Disconnect.
-        self.disconnect()
-
-        # Reset the typing handler
-        self.hs.get_replication_streams()["typing"].last_token = 0
-        self.hs.get_replication_command_handler()._streams["typing"].last_token = 0
-        typing._latest_room_serial = 0
-        typing._typing_stream_change_cache = StreamChangeCache(
-            name="TypingStreamChangeCache",
-            server_name=self.hs.hostname,
-            current_stream_pos=typing._latest_room_serial,
-        )
-        typing._reset()
-
-        # Reconnect.
-        self.reconnect()
-        self.pump(0.1)
-
-        # We should now see an attempt to connect to the master
-        request = self.handle_http_replication_attempt()
-        self.assert_request_is_get_repl_stream_updates(request, "typing")
-
-        # Reset the test code.
-        self.mock_handler.on_rdata.reset_mock()
-        self.mock_handler.on_rdata.assert_not_called()
-
-        # Push additional data.
-        typing._push_update(member=RoomMember(ROOM_ID_2, USER_ID_2), typing=False)
-        self.reactor.advance(0)
-
-        self.mock_handler.on_rdata.assert_called_once()
-        stream_name, _, token, rdata_rows = self.mock_handler.on_rdata.call_args[0]
-        self.assertEqual(stream_name, "typing")
-        self.assertEqual(1, len(rdata_rows))
-        row = rdata_rows[0]
-        self.assertEqual(ROOM_ID_2, row.room_id)
-        self.assertEqual([], row.user_ids)
-
-        # The token should have been reset.
-        self.assertEqual(token, 1)
+            typing._reset()
+
+            # Reconnect.
+            self.reconnect()
+            self.pump(0.1)
+
+            # We should now see an attempt to connect to the master
+            request = self.handle_http_replication_attempt()
+            self.assert_request_is_get_repl_stream_updates(request, "typing")
+
+            # Reset the test code.
+            self.mock_handler.on_rdata.reset_mock()
+            self.mock_handler.on_rdata.assert_not_called()
+
+            # Push additional data.
+            typing._push_update(member=RoomMember(ROOM_ID_2, USER_ID_2), typing=False)
+            self.reactor.advance(0)
+
+            self.mock_handler.on_rdata.assert_called_once()
+            stream_name, _, token, rdata_rows = self.mock_handler.on_rdata.call_args[0]
+            self.assertEqual(stream_name, "typing")
+            self.assertEqual(1, len(rdata_rows))
+            row = rdata_rows[0]
+            self.assertEqual(ROOM_ID_2, row.room_id)
+            self.assertEqual([], row.user_ids)
+
+            # The token should have been reset.
+            self.assertEqual(token, 1)
+        finally:
+            server_logger.disabled = server_logger_was_disabled

tests/rest/client/test_profile.py

@@ -21,6 +21,7 @@
 
 """Tests REST events for /profile paths."""
 
+import logging
 import urllib.parse
 from http import HTTPStatus
 from typing import Any, Dict, Optional
@@ -648,87 +649,99 @@ def test_set_custom_field_profile_too_long(self) -> None:
         """
         Attempts to set a custom field that would push the overall profile too large.
         """
-        # Get right to the boundary:
-        #   len("displayname") + len("owner") + 5 = 21 for the displayname
-        #   1 + 65498 + 5 for key "a" = 65504
-        #   2 braces, 1 comma
-        # 3 + 21 + 65498 = 65522 < 65536.
-        key = "a"
-        channel = self.make_request(
-            "PUT",
-            f"/_matrix/client/v3/profile/{self.owner}/{key}",
-            content={key: "a" * 65498},
-            access_token=self.owner_tok,
-        )
-        self.assertEqual(channel.code, 200, channel.result)
-
-        # Get the entire profile.
-        channel = self.make_request(
-            "GET",
-            f"/_matrix/client/v3/profile/{self.owner}",
-            access_token=self.owner_tok,
-        )
-        self.assertEqual(channel.code, 200, channel.result)
-        canonical_json = encode_canonical_json(channel.json_body)
-        # 6 is the minimum bytes to store a value: 4 quotes, 1 colon, 1 comma, an empty key.
-        # Be one below that so we can prove we're at the boundary.
-        self.assertEqual(len(canonical_json), MAX_PROFILE_SIZE - 8)
-
-        # Postgres stores JSONB with whitespace, while SQLite doesn't.
-        if USE_POSTGRES_FOR_TESTS:
-            ADDITIONAL_CHARS = 0
-        else:
-            ADDITIONAL_CHARS = 1
+        # FIXME: Because we emit huge SQL log lines and trial can't handle these,
+        # sometimes (flakily) failing the test run,
+        # disable SQL logging for this test.
+        # ref: https://github.com/twisted/twisted/issues/12482
+        # To remove this, we would need to fix the above issue and
+        # update, including in olddeps (so several years' wait).
+        sql_logger = logging.getLogger("synapse.storage.SQL")
+        sql_logger_was_disabled = sql_logger.disabled
+        sql_logger.disabled = True
+        try:
+            # Get right to the boundary:
+            #   len("displayname") + len("owner") + 5 = 21 for the displayname
+            #   1 + 65498 + 5 for key "a" = 65504
+            #   2 braces, 1 comma
+            # 3 + 21 + 65498 = 65522 < 65536.
+            key = "a"
+            channel = self.make_request(
+                "PUT",
+                f"/_matrix/client/v3/profile/{self.owner}/{key}",
+                content={key: "a" * 65498},
+                access_token=self.owner_tok,
+            )
+            self.assertEqual(channel.code, 200, channel.result)
 
-        # The next one should fail, note the value has a (JSON) length of 2.
-        key = "b"
-        channel = self.make_request(
-            "PUT",
-            f"/_matrix/client/v3/profile/{self.owner}/{key}",
-            content={key: "1" + "a" * ADDITIONAL_CHARS},
-            access_token=self.owner_tok,
-        )
-        self.assertEqual(channel.code, 400, channel.result)
-        self.assertEqual(channel.json_body["errcode"], Codes.PROFILE_TOO_LARGE)
+            # Get the entire profile.
+            channel = self.make_request(
+                "GET",
+                f"/_matrix/client/v3/profile/{self.owner}",
+                access_token=self.owner_tok,
+            )
+            self.assertEqual(channel.code, 200, channel.result)
+            canonical_json = encode_canonical_json(channel.json_body)
+            # 6 is the minimum bytes to store a value: 4 quotes, 1 colon, 1 comma, an empty key.
+            # Be one below that so we can prove we're at the boundary.
+            self.assertEqual(len(canonical_json), MAX_PROFILE_SIZE - 8)
+
+            # Postgres stores JSONB with whitespace, while SQLite doesn't.
+            if USE_POSTGRES_FOR_TESTS:
+                ADDITIONAL_CHARS = 0
+            else:
+                ADDITIONAL_CHARS = 1
+
+            # The next one should fail, note the value has a (JSON) length of 2.
+            key = "b"
+            channel = self.make_request(
+                "PUT",
+                f"/_matrix/client/v3/profile/{self.owner}/{key}",
+                content={key: "1" + "a" * ADDITIONAL_CHARS},
+                access_token=self.owner_tok,
+            )
+            self.assertEqual(channel.code, 400, channel.result)
+            self.assertEqual(channel.json_body["errcode"], Codes.PROFILE_TOO_LARGE)
 
-        # Setting an avatar or (longer) display name should not work.
-        channel = self.make_request(
-            "PUT",
-            f"/profile/{self.owner}/displayname",
-            content={"displayname": "owner12345678" + "a" * ADDITIONAL_CHARS},
-            access_token=self.owner_tok,
-        )
-        self.assertEqual(channel.code, 400, channel.result)
-        self.assertEqual(channel.json_body["errcode"], Codes.PROFILE_TOO_LARGE)
+            # Setting an avatar or (longer) display name should not work.
+            channel = self.make_request(
+                "PUT",
+                f"/profile/{self.owner}/displayname",
+                content={"displayname": "owner12345678" + "a" * ADDITIONAL_CHARS},
+                access_token=self.owner_tok,
+            )
+            self.assertEqual(channel.code, 400, channel.result)
+            self.assertEqual(channel.json_body["errcode"], Codes.PROFILE_TOO_LARGE)
 
-        channel = self.make_request(
-            "PUT",
-            f"/profile/{self.owner}/avatar_url",
-            content={"avatar_url": "mxc://foo/bar"},
-            access_token=self.owner_tok,
-        )
-        self.assertEqual(channel.code, 400, channel.result)
-        self.assertEqual(channel.json_body["errcode"], Codes.PROFILE_TOO_LARGE)
+            channel = self.make_request(
+                "PUT",
+                f"/profile/{self.owner}/avatar_url",
+                content={"avatar_url": "mxc://foo/bar"},
+                access_token=self.owner_tok,
+            )
+            self.assertEqual(channel.code, 400, channel.result)
+            self.assertEqual(channel.json_body["errcode"], Codes.PROFILE_TOO_LARGE)
 
-        # Removing a single byte should work.
-        key = "b"
-        channel = self.make_request(
-            "PUT",
-            f"/_matrix/client/v3/profile/{self.owner}/{key}",
-            content={key: "" + "a" * ADDITIONAL_CHARS},
-            access_token=self.owner_tok,
-        )
-        self.assertEqual(channel.code, 200, channel.result)
+            # Removing a single byte should work.
+            key = "b"
+            channel = self.make_request(
+                "PUT",
+                f"/_matrix/client/v3/profile/{self.owner}/{key}",
+                content={key: "" + "a" * ADDITIONAL_CHARS},
+                access_token=self.owner_tok,
+            )
+            self.assertEqual(channel.code, 200, channel.result)
 
-        # Finally, setting a field that already exists to a value that is <= in length should work.
-        key = "a"
-        channel = self.make_request(
-            "PUT",
-            f"/_matrix/client/v3/profile/{self.owner}/{key}",
-            content={key: ""},
-            access_token=self.owner_tok,
-        )
-        self.assertEqual(channel.code, 200, channel.result)
+            # Finally, setting a field that already exists to a value that is <= in length should work.
+            key = "a"
+            channel = self.make_request(
+                "PUT",
+                f"/_matrix/client/v3/profile/{self.owner}/{key}",
+                content={key: ""},
+                access_token=self.owner_tok,
+            )
+            self.assertEqual(channel.code, 200, channel.result)
+        finally:
+            sql_logger.disabled = sql_logger_was_disabled
 
     def test_set_custom_field_displayname(self) -> None:
         channel = self.make_request(