logging.py 3.6 KB

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