logging.py 4.2 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145
  1. # Copyright 2019 The Matrix.org Foundation C.I.C.
  2. #
  3. # Licensed under the Apache License, Version 2.0 (the "License");
  4. # you may not use this file except in compliance with the License.
  5. # You may obtain a copy of the License at
  6. #
  7. # http://www.apache.org/licenses/LICENSE-2.0
  8. #
  9. # Unless required by applicable law or agreed to in writing, software
  10. # distributed under the License is distributed on an "AS IS" BASIS,
  11. # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  12. # See the License for the specific language governing permissions and
  13. # limitations under the License.
  14. import logging
  15. import logging.config
  16. import warnings
  17. from io import StringIO
  18. from typing import Optional
  19. from unittest.mock import Mock
  20. from pyperf import perf_counter
  21. from twisted.internet.address import IPv4Address, IPv6Address
  22. from twisted.internet.defer import Deferred
  23. from twisted.internet.protocol import ServerFactory
  24. from twisted.logger import LogBeginner, LogPublisher
  25. from twisted.protocols.basic import LineOnlyReceiver
  26. from synapse.config.logger import _setup_stdlib_logging
  27. from synapse.logging import RemoteHandler
  28. from synapse.synapse_rust import reset_logging_config
  29. from synapse.types import ISynapseReactor
  30. from synapse.util import Clock
  31. class LineCounter(LineOnlyReceiver):
  32. delimiter = b"\n"
  33. count = 0
  34. def lineReceived(self, line: bytes) -> None:
  35. self.count += 1
  36. assert isinstance(self.factory, Factory)
  37. if self.count >= self.factory.wait_for and self.factory.on_done:
  38. on_done = self.factory.on_done
  39. self.factory.on_done = None
  40. on_done.callback(True)
  41. class Factory(ServerFactory):
  42. protocol = LineCounter
  43. wait_for: int
  44. on_done: Optional[Deferred]
  45. async def main(reactor: ISynapseReactor, loops: int) -> float:
  46. """
  47. Benchmark how long it takes to send `loops` messages.
  48. """
  49. logger_factory = Factory()
  50. logger_factory.wait_for = loops
  51. logger_factory.on_done = Deferred()
  52. port = reactor.listenTCP(0, logger_factory, backlog=50, interface="127.0.0.1")
  53. # A fake homeserver config.
  54. class Config:
  55. class server:
  56. server_name = "synmark-" + str(loops)
  57. # This odd construct is to avoid mypy thinking that logging escapes the
  58. # scope of Config.
  59. class _logging:
  60. no_redirect_stdio = True
  61. logging = _logging
  62. hs_config = Config()
  63. # To be able to sleep.
  64. clock = Clock(reactor)
  65. errors = StringIO()
  66. publisher = LogPublisher()
  67. mock_sys = Mock()
  68. beginner = LogBeginner(
  69. publisher, errors, mock_sys, warnings, initialBufferSize=loops
  70. )
  71. address = port.getHost()
  72. assert isinstance(address, (IPv4Address, IPv6Address))
  73. log_config = {
  74. "version": 1,
  75. "loggers": {"synapse": {"level": "DEBUG", "handlers": ["remote"]}},
  76. "formatters": {"tersejson": {"class": "synapse.logging.TerseJsonFormatter"}},
  77. "handlers": {
  78. "remote": {
  79. "class": "synapse.logging.RemoteHandler",
  80. "formatter": "tersejson",
  81. "host": address.host,
  82. "port": address.port,
  83. "maximum_buffer": 100,
  84. }
  85. },
  86. }
  87. logger = logging.getLogger("synapse")
  88. _setup_stdlib_logging(
  89. hs_config, # type: ignore[arg-type]
  90. None,
  91. logBeginner=beginner,
  92. )
  93. # Force a new logging config without having to load it from a file.
  94. logging.config.dictConfig(log_config)
  95. reset_logging_config()
  96. # Wait for it to connect...
  97. for handler in logging.getLogger("synapse").handlers:
  98. if isinstance(handler, RemoteHandler):
  99. break
  100. else:
  101. raise RuntimeError("Improperly configured: no RemoteHandler found.")
  102. await handler._service.whenConnected(failAfterFailures=10)
  103. start = perf_counter()
  104. # Send a bunch of useful messages
  105. for i in range(loops):
  106. logger.info("test message %s", i)
  107. if len(handler._buffer) == handler.maximum_buffer:
  108. while len(handler._buffer) > handler.maximum_buffer / 2:
  109. await clock.sleep(0.01)
  110. await logger_factory.on_done
  111. end = perf_counter() - start
  112. handler.close()
  113. port.stopListening()
  114. return end