logging.py 3.6 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130
  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 warnings
  16. from io import StringIO
  17. from unittest.mock import Mock
  18. from pyperf import perf_counter
  19. from twisted.internet.defer import Deferred
  20. from twisted.internet.protocol import ServerFactory
  21. from twisted.logger import LogBeginner, LogPublisher
  22. from twisted.protocols.basic import LineOnlyReceiver
  23. from synapse.config.logger import _setup_stdlib_logging
  24. from synapse.logging import RemoteHandler
  25. from synapse.util import Clock
  26. class LineCounter(LineOnlyReceiver):
  27. delimiter = b"\n"
  28. def __init__(self, *args, **kwargs):
  29. self.count = 0
  30. super().__init__(*args, **kwargs)
  31. def lineReceived(self, line):
  32. self.count += 1
  33. if self.count >= self.factory.wait_for and self.factory.on_done:
  34. on_done = self.factory.on_done
  35. self.factory.on_done = None
  36. on_done.callback(True)
  37. async def main(reactor, loops):
  38. """
  39. Benchmark how long it takes to send `loops` messages.
  40. """
  41. servers = []
  42. def protocol():
  43. p = LineCounter()
  44. servers.append(p)
  45. return p
  46. logger_factory = ServerFactory.forProtocol(protocol)
  47. logger_factory.wait_for = loops
  48. logger_factory.on_done = Deferred()
  49. port = reactor.listenTCP(0, logger_factory, interface="127.0.0.1")
  50. # A fake homeserver config.
  51. class Config:
  52. server_name = "synmark-" + str(loops)
  53. no_redirect_stdio = True
  54. hs_config = Config()
  55. # To be able to sleep.
  56. clock = Clock(reactor)
  57. errors = StringIO()
  58. publisher = LogPublisher()
  59. mock_sys = Mock()
  60. beginner = LogBeginner(
  61. publisher, errors, mock_sys, warnings, initialBufferSize=loops
  62. )
  63. log_config = {
  64. "version": 1,
  65. "loggers": {"synapse": {"level": "DEBUG", "handlers": ["tersejson"]}},
  66. "formatters": {"tersejson": {"class": "synapse.logging.TerseJsonFormatter"}},
  67. "handlers": {
  68. "tersejson": {
  69. "class": "synapse.logging.RemoteHandler",
  70. "host": "127.0.0.1",
  71. "port": port.getHost().port,
  72. "maximum_buffer": 100,
  73. "_reactor": reactor,
  74. }
  75. },
  76. }
  77. logger = logging.getLogger("synapse.logging.test_terse_json")
  78. _setup_stdlib_logging(
  79. hs_config,
  80. log_config,
  81. logBeginner=beginner,
  82. )
  83. # Wait for it to connect...
  84. for handler in logging.getLogger("synapse").handlers:
  85. if isinstance(handler, RemoteHandler):
  86. break
  87. else:
  88. raise RuntimeError("Improperly configured: no RemoteHandler found.")
  89. await handler._service.whenConnected()
  90. start = perf_counter()
  91. # Send a bunch of useful messages
  92. for i in range(0, loops):
  93. logger.info("test message %s", i)
  94. if len(handler._buffer) == handler.maximum_buffer:
  95. while len(handler._buffer) > handler.maximum_buffer / 2:
  96. await clock.sleep(0.01)
  97. await logger_factory.on_done
  98. end = perf_counter() - start
  99. handler.close()
  100. port.stopListening()
  101. return end