Fix RemoteHandler no longer sending logs after connecting (#20389)

Fixes #17480

Once `RemoteHandler` is connected, `whenConnected` returns a Deferred
that has already fired, so `writer` runs synchronously inside
`addCallbacks` and clears `_connection_waiter`. The next line then set
the waiter to that fired Deferred, so every later `_connect` call
returned early and logs stopped after the first line or two.

This sets the waiter before adding the callbacks, so a callback that
runs right away can still clear it. The new test logs a few more lines
over an existing connection and checks that they all arrive.

The bug came in with #9591, hence v1.30.0 in the changelog.

Thanks to @haarp for tracking this down and for the detailed
reproduction steps.

### Pull Request Checklist

<!-- Please read
https://element-hq.github.io/synapse/latest/development/contributing_guide.html
before submitting your pull request -->

* [x] Pull request is based on the develop branch
* [x] Pull request includes a [changelog
file](https://element-hq.github.io/synapse/latest/development/contributing_guide.html#changelog).
The entry should:
- Be a short description of your change which makes sense to users.
"Fixed a bug that prevented receiving messages from other servers."
instead of "Moved X method from `EventStore` to `EventWorkerStore`.".
  - Use markdown where necessary, mostly for `code blocks`.
  - End with either a period (.) or an exclamation mark (!).
  - Start with a capital letter.
- Feel free to credit yourself, by adding a sentence "Contributed by
@github_username." or "Contributed by [Your Name]." to the end of the
entry.
* [x] [Code
style](https://element-hq.github.io/synapse/latest/code_style.html) is
correct (run the
[linters](https://element-hq.github.io/synapse/latest/development/contributing_guide.html#run-the-linters))

changelog.d/20389.bugfix

@@ -0,0 +1 @@
+Fix a bug introduced in Synapse v1.30.0 where `synapse.logging.RemoteHandler` stopped sending logs shortly after connecting. Thanks to @haarp for the diagnosis.

synapse/logging/_remote.py

@@ -198,9 +198,11 @@ class RemoteHandler(logging.Handler):
             self._producer.resumeProducing()
             self._connection_waiter = None
 
+        # Set the waiter before adding callbacks: if we are already connected
+        # they run synchronously and clear it again.
         deferred: Deferred = self._service.whenConnected(failAfterFailures=1)
-        deferred.addCallbacks(writer, fail)
         self._connection_waiter = deferred
+        deferred.addCallbacks(writer, fail)
 
     def _handle_pressure(self) -> None:
         """

tests/logging/test_remote_handler.py

@@ -75,6 +75,31 @@ class RemoteHandlerTestCase(LoggerCleanupMixin, TestCase):
         # Ensure the data passed through properly.
         self.assertEqual(logs[0], "Hello there, wally!")
 
+    def test_log_output_after_connecting(self) -> None:
+        """
+        The remote handler keeps delivering logs once it is connected.
+        """
+        handler = RemoteHandler("127.0.0.1", 9000, _reactor=self.reactor)
+        logger = self.get_logger(handler)
+
+        logger.info("Hello there, %s!", "wally")
+
+        # Trigger the connection
+        client, server = connect_logging_client(self.reactor, 0)
+        client_transport = checked_cast(FakeTransport, client.transport)
+        client_transport.flush()
+
+        # Log over the existing connection
+        for i in range(3):
+            logger.info("more %s", i)
+            client_transport.flush()
+
+        logs = server.data.decode("utf8").splitlines()
+        self.assertEqual(
+            ["Hello there, wally!", "more 0", "more 1", "more 2"],
+            logs,
+        )
+
     def test_log_backpressure_debug(self) -> None:
         """
         When backpressure is hit, DEBUG logs will be shed.