2019-12-03 04:21:25 -05:00
|
|
|
#
|
2023-11-21 15:29:58 -05:00
|
|
|
# This file is licensed under the Affero General Public License (AGPL) version 3.
|
|
|
|
#
|
2024-01-23 06:26:48 -05:00
|
|
|
# Copyright 2019 The Matrix.org Foundation C.I.C.
|
2023-11-21 15:29:58 -05:00
|
|
|
# Copyright (C) 2023 New Vector, Ltd
|
|
|
|
#
|
|
|
|
# This program is free software: you can redistribute it and/or modify
|
|
|
|
# it under the terms of the GNU Affero General Public License as
|
|
|
|
# published by the Free Software Foundation, either version 3 of the
|
|
|
|
# License, or (at your option) any later version.
|
|
|
|
#
|
|
|
|
# See the GNU Affero General Public License for more details:
|
|
|
|
# <https://www.gnu.org/licenses/agpl-3.0.html>.
|
|
|
|
#
|
|
|
|
# Originally licensed under the Apache License, Version 2.0:
|
|
|
|
# <http://www.apache.org/licenses/LICENSE-2.0>.
|
|
|
|
#
|
|
|
|
# [This file includes modifications made by New Vector Limited]
|
2019-12-03 04:21:25 -05:00
|
|
|
#
|
|
|
|
#
|
2020-10-29 07:27:37 -04:00
|
|
|
import logging
|
2023-10-04 13:53:04 -04:00
|
|
|
import logging.config
|
2019-12-03 04:21:25 -05:00
|
|
|
import warnings
|
|
|
|
from io import StringIO
|
2023-10-04 13:53:04 -04:00
|
|
|
from typing import Optional
|
2021-04-09 13:44:38 -04:00
|
|
|
from unittest.mock import Mock
|
2019-12-03 04:21:25 -05:00
|
|
|
|
|
|
|
from pyperf import perf_counter
|
|
|
|
|
2023-10-04 13:53:04 -04:00
|
|
|
from twisted.internet.address import IPv4Address, IPv6Address
|
2019-12-03 04:21:25 -05:00
|
|
|
from twisted.internet.defer import Deferred
|
|
|
|
from twisted.internet.protocol import ServerFactory
|
2020-10-29 07:27:37 -04:00
|
|
|
from twisted.logger import LogBeginner, LogPublisher
|
2019-12-03 04:21:25 -05:00
|
|
|
from twisted.protocols.basic import LineOnlyReceiver
|
|
|
|
|
2020-10-29 07:27:37 -04:00
|
|
|
from synapse.config.logger import _setup_stdlib_logging
|
|
|
|
from synapse.logging import RemoteHandler
|
2023-10-04 13:53:04 -04:00
|
|
|
from synapse.synapse_rust import reset_logging_config
|
|
|
|
from synapse.types import ISynapseReactor
|
2020-10-29 07:27:37 -04:00
|
|
|
from synapse.util import Clock
|
2019-12-03 04:21:25 -05:00
|
|
|
|
|
|
|
|
|
|
|
class LineCounter(LineOnlyReceiver):
|
|
|
|
delimiter = b"\n"
|
2023-10-04 13:53:04 -04:00
|
|
|
count = 0
|
2019-12-03 04:21:25 -05:00
|
|
|
|
2023-10-04 13:53:04 -04:00
|
|
|
def lineReceived(self, line: bytes) -> None:
|
2019-12-03 04:21:25 -05:00
|
|
|
self.count += 1
|
|
|
|
|
2023-10-04 13:53:04 -04:00
|
|
|
assert isinstance(self.factory, Factory)
|
|
|
|
|
2019-12-03 04:21:25 -05:00
|
|
|
if self.count >= self.factory.wait_for and self.factory.on_done:
|
|
|
|
on_done = self.factory.on_done
|
|
|
|
self.factory.on_done = None
|
|
|
|
on_done.callback(True)
|
|
|
|
|
|
|
|
|
2023-10-04 13:53:04 -04:00
|
|
|
class Factory(ServerFactory):
|
|
|
|
protocol = LineCounter
|
|
|
|
wait_for: int
|
|
|
|
on_done: Optional[Deferred]
|
|
|
|
|
|
|
|
|
|
|
|
async def main(reactor: ISynapseReactor, loops: int) -> float:
|
2019-12-03 04:21:25 -05:00
|
|
|
"""
|
|
|
|
Benchmark how long it takes to send `loops` messages.
|
|
|
|
"""
|
|
|
|
|
2023-10-04 13:53:04 -04:00
|
|
|
logger_factory = Factory()
|
2019-12-03 04:21:25 -05:00
|
|
|
logger_factory.wait_for = loops
|
|
|
|
logger_factory.on_done = Deferred()
|
2023-10-04 13:53:04 -04:00
|
|
|
port = reactor.listenTCP(0, logger_factory, backlog=50, interface="127.0.0.1")
|
2019-12-03 04:21:25 -05:00
|
|
|
|
2020-10-29 07:27:37 -04:00
|
|
|
# A fake homeserver config.
|
|
|
|
class Config:
|
2023-10-04 13:53:04 -04:00
|
|
|
class server:
|
|
|
|
server_name = "synmark-" + str(loops)
|
|
|
|
|
|
|
|
# This odd construct is to avoid mypy thinking that logging escapes the
|
|
|
|
# scope of Config.
|
|
|
|
class _logging:
|
|
|
|
no_redirect_stdio = True
|
|
|
|
|
|
|
|
logging = _logging
|
2020-10-29 07:27:37 -04:00
|
|
|
|
|
|
|
hs_config = Config()
|
|
|
|
|
|
|
|
# To be able to sleep.
|
|
|
|
clock = Clock(reactor)
|
2019-12-03 04:21:25 -05:00
|
|
|
|
|
|
|
errors = StringIO()
|
|
|
|
publisher = LogPublisher()
|
|
|
|
mock_sys = Mock()
|
|
|
|
beginner = LogBeginner(
|
|
|
|
publisher, errors, mock_sys, warnings, initialBufferSize=loops
|
|
|
|
)
|
|
|
|
|
2023-10-04 13:53:04 -04:00
|
|
|
address = port.getHost()
|
|
|
|
assert isinstance(address, (IPv4Address, IPv6Address))
|
2019-12-03 04:21:25 -05:00
|
|
|
log_config = {
|
2020-10-29 07:27:37 -04:00
|
|
|
"version": 1,
|
2023-10-04 13:53:04 -04:00
|
|
|
"loggers": {"synapse": {"level": "DEBUG", "handlers": ["remote"]}},
|
2020-10-29 07:27:37 -04:00
|
|
|
"formatters": {"tersejson": {"class": "synapse.logging.TerseJsonFormatter"}},
|
|
|
|
"handlers": {
|
2023-10-04 13:53:04 -04:00
|
|
|
"remote": {
|
2020-10-29 07:27:37 -04:00
|
|
|
"class": "synapse.logging.RemoteHandler",
|
2023-10-04 13:53:04 -04:00
|
|
|
"formatter": "tersejson",
|
|
|
|
"host": address.host,
|
|
|
|
"port": address.port,
|
2019-12-03 04:21:25 -05:00
|
|
|
"maximum_buffer": 100,
|
|
|
|
}
|
|
|
|
},
|
|
|
|
}
|
|
|
|
|
2023-10-04 13:53:04 -04:00
|
|
|
logger = logging.getLogger("synapse")
|
2020-10-29 07:27:37 -04:00
|
|
|
_setup_stdlib_logging(
|
2023-10-04 13:53:04 -04:00
|
|
|
hs_config, # type: ignore[arg-type]
|
|
|
|
None,
|
2021-02-16 17:32:34 -05:00
|
|
|
logBeginner=beginner,
|
2019-12-03 04:21:25 -05:00
|
|
|
)
|
|
|
|
|
2023-10-04 13:53:04 -04:00
|
|
|
# Force a new logging config without having to load it from a file.
|
|
|
|
logging.config.dictConfig(log_config)
|
|
|
|
reset_logging_config()
|
|
|
|
|
2019-12-03 04:21:25 -05:00
|
|
|
# Wait for it to connect...
|
2020-10-29 07:27:37 -04:00
|
|
|
for handler in logging.getLogger("synapse").handlers:
|
|
|
|
if isinstance(handler, RemoteHandler):
|
|
|
|
break
|
|
|
|
else:
|
|
|
|
raise RuntimeError("Improperly configured: no RemoteHandler found.")
|
|
|
|
|
2023-10-04 13:53:04 -04:00
|
|
|
await handler._service.whenConnected(failAfterFailures=10)
|
2019-12-03 04:21:25 -05:00
|
|
|
|
|
|
|
start = perf_counter()
|
|
|
|
|
|
|
|
# Send a bunch of useful messages
|
2023-09-08 11:24:36 -04:00
|
|
|
for i in range(loops):
|
2020-10-29 07:27:37 -04:00
|
|
|
logger.info("test message %s", i)
|
|
|
|
|
|
|
|
if len(handler._buffer) == handler.maximum_buffer:
|
|
|
|
while len(handler._buffer) > handler.maximum_buffer / 2:
|
|
|
|
await clock.sleep(0.01)
|
2019-12-03 04:21:25 -05:00
|
|
|
|
|
|
|
await logger_factory.on_done
|
|
|
|
|
|
|
|
end = perf_counter() - start
|
|
|
|
|
2020-10-29 07:27:37 -04:00
|
|
|
handler.close()
|
2019-12-03 04:21:25 -05:00
|
|
|
port.stopListening()
|
|
|
|
|
|
|
|
return end
|