Skip to content

Commit

Permalink
Revert "remove testsuite logging plugin (#99)"
Browse files Browse the repository at this point in the history
This reverts commit e4a244d.
  • Loading branch information
vitek committed May 30, 2024
1 parent d7335d2 commit cc74826
Show file tree
Hide file tree
Showing 8 changed files with 303 additions and 45 deletions.
10 changes: 10 additions & 0 deletions tests/daemons/test_service_daemon.py
Original file line number Diff line number Diff line change
Expand Up @@ -40,13 +40,20 @@ def dummy_daemon(mockserver):
return pathlib.Path(__file__).parent / 'daemons/dummy_daemon.py'


@pytest.fixture
def logger_plugin(pytestconfig):
return pytestconfig.pluginmanager.getplugin('testsuite_logger')


async def test_service_daemon(
mockserver,
dummy_daemon,
logger_plugin,
health_check,
):
async with service_daemon.start(
args=[sys.executable, dummy_daemon],
logger_plugin=logger_plugin,
health_check=health_check,
subprocess_options={'stdout': subprocess.PIPE, 'bufsize': 0},
):
Expand All @@ -58,6 +65,7 @@ async def test_service_daemon(
async def test_service_wait_custom_health(
mockserver,
dummy_daemon,
logger_plugin,
pytestconfig,
wait_service_started,
):
Expand Down Expand Up @@ -91,13 +99,15 @@ async def test_service_daemon_failure(
dummy_daemon,
daemon_args,
expected_message,
logger_plugin,
health_check,
):
with pytest.raises(spawn.ExitCodeError) as exc:
start_command = [dummy_daemon] + daemon_args
async with service_daemon.start(
start_command,
health_check=health_check,
logger_plugin=logger_plugin,
subprocess_options={'stdout': subprocess.PIPE, 'bufsize': 0},
):
pass
Expand Down
22 changes: 16 additions & 6 deletions testsuite/daemons/pytest_plugin.py
Original file line number Diff line number Diff line change
Expand Up @@ -59,8 +59,9 @@ async def aclose(self) -> None:
class _DaemonStore:
cells: Dict[str, DaemonInstance]

def __init__(self) -> None:
def __init__(self, logger_plugin) -> None:
self.cells = {}
self.logger_plugin = logger_plugin

async def aclose(self) -> None:
for daemon in self.cells.values():
Expand Down Expand Up @@ -96,7 +97,9 @@ def has_running_daemons(self) -> bool:
return False

async def _close_daemon(self, daemon: DaemonInstance):
await daemon.aclose()
with self.logger_plugin.temporary_suspend() as log_manager:
await daemon.aclose()
log_manager.clear()


class EnsureDaemonStartedFixture(fixture_class.Fixture):
Expand Down Expand Up @@ -155,11 +158,16 @@ def __call__(
warnings.warn(CHECK_URL_DEPRECATION, PendingDeprecationWarning)

pytestconfig = self._fixture_pytestconfig
logger_plugin = pytestconfig.pluginmanager.getplugin(
'testsuite_logger',
)

shutdown_timeout = pytestconfig.option.service_shutdown_timeout
shutdown_timeout = (
self._fixture_pytestconfig.option.service_shutdown_timeout
)
if shutdown_signal is None:
shutdown_signal = SHUTDOWN_SIGNALS[
pytestconfig.option.service_shutdown_signal
self._fixture_pytestconfig.option.service_shutdown_signal
]

health_check = service_daemon.make_health_check(
Expand Down Expand Up @@ -190,6 +198,7 @@ async def spawn():
session_factory=self._fixture_service_client_session_factory,
subprocess_options=subprocess_options,
setup_service=setup_service,
logger_plugin=logger_plugin,
subprocess_spawner=subprocess_spawner,
stdout_handler=stdout_handler,
stderr_handler=stderr_handler,
Expand Down Expand Up @@ -425,8 +434,9 @@ def service_client_options(


@pytest.fixture(scope='session')
async def _global_daemon_store(loop):
store = _DaemonStore()
async def _global_daemon_store(loop, pytestconfig):
logger_plugin = pytestconfig.pluginmanager.getplugin('testsuite_logger')
store = _DaemonStore(logger_plugin)
async with compat.aclosing(store):
yield store

Expand Down
36 changes: 20 additions & 16 deletions testsuite/daemons/service_daemon.py
Original file line number Diff line number Diff line change
Expand Up @@ -33,6 +33,7 @@ async def start(
*,
health_check: HealthCheckType,
session_factory: ClientSessionFactory = aiohttp.ClientSession,
logger_plugin,
env: Optional[Dict[str, str]] = None,
shutdown_signal: int = signal.SIGINT,
shutdown_timeout: float = 120,
Expand All @@ -43,22 +44,25 @@ async def start(
stdout_handler=None,
stderr_handler=None,
) -> AsyncGenerator[Optional[subprocess.Popen], None]:
async with session_factory() as session:
async with _service_daemon(
args=args,
env=env,
shutdown_signal=shutdown_signal,
shutdown_timeout=shutdown_timeout,
poll_retries=poll_retries,
subprocess_options=subprocess_options,
setup_service=setup_service,
subprocess_spawner=subprocess_spawner,
health_check=health_check,
session=session,
stdout_handler=stdout_handler,
stderr_handler=stderr_handler,
) as process:
yield process
with logger_plugin.temporary_suspend() as log_manager:
async with session_factory() as session:
async with _service_daemon(
args=args,
env=env,
shutdown_signal=shutdown_signal,
shutdown_timeout=shutdown_timeout,
poll_retries=poll_retries,
subprocess_options=subprocess_options,
setup_service=setup_service,
subprocess_spawner=subprocess_spawner,
health_check=health_check,
session=session,
stdout_handler=stdout_handler,
stderr_handler=stderr_handler,
) as process:
log_manager.clear()
log_manager.resume()
yield process


async def service_wait(
Expand Down
25 changes: 2 additions & 23 deletions testsuite/environment/main.py
Original file line number Diff line number Diff line change
Expand Up @@ -6,7 +6,7 @@
import subprocess
import sys

from testsuite.utils import colors
from testsuite.logging import logger as testsuite_logger

from . import control
from . import shell
Expand All @@ -24,27 +24,6 @@
logger = logging.getLogger(__name__)


class ColoredLevelFormatter(logging.Formatter):
LEVEL_COLORS = {
logging.DEBUG: colors.Colors.GRAY,
logging.INFO: colors.Colors.BRIGHT_GREEN,
logging.WARNING: colors.Colors.YELLOW,
logging.ERROR: colors.Colors.RED,
logging.CRITICAL: colors.Colors.BRIGHT_RED,
}

def __init__(self, *, colors_enabled=False):
super().__init__()
self._colors_enabled = colors_enabled

def format(self, record: logging.LogRecord):
message = super().format(record)
if not self._colors_enabled:
return f'{record.levelname} {message}'
color = self.LEVEL_COLORS.get(record.levelno, colors.Colors.DEFAULT)
return f'{color}{record.levelname}{colors.Colors.DEFAULT} {message}'


def csv_arg(value: str):
result = []
for arg in value.split(','):
Expand Down Expand Up @@ -136,7 +115,7 @@ def _setup_logging(log_level):
root_logger.setLevel(log_level)
handler = logging.StreamHandler(sys.stderr)
handler.setFormatter(
ColoredLevelFormatter(
testsuite_logger.ColoredLevelFormatter(
colors_enabled=sys.stderr.isatty(),
),
)
Expand Down
Empty file added testsuite/logging/__init__.py
Empty file.
147 changes: 147 additions & 0 deletions testsuite/logging/logger.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,147 @@
import contextlib
import logging
import threading
import typing

from testsuite.utils import colors
from testsuite.utils import tskv


class Manager:
def __init__(
self,
line_logger: 'LineLogger',
output: typing.IO,
ensure_newline: bool,
):
self._line_logger = line_logger
self._output = output
self._ensure_newline = ensure_newline
self._resumed = False

def resume(self):
if not self._resumed:
self._line_logger.resume(self._output, self._ensure_newline)
self._resumed = True

def clear(self):
self._line_logger.clear()


class LineLogger:
def __init__(self):
self._buffer = []
self._ensure_newline = False
self._lock = threading.Lock()
self._output = None

def writeline(self, line: str) -> None:
with self._lock:
if self._output:
try:
self._writeline(line)
except ValueError:
if not self._output.closed:
raise
# Capture manager closed output buffer.
self._output = None
if not self._output:
self._buffer.append(line)

def resume(self, output, ensure_newline=True):
with self._lock:
self._output = output
self._ensure_newline = ensure_newline
self._flush_buffer()

def suspend(self):
with self._lock:
self._output = None

def clear(self):
with self._lock:
self._buffer = []

@contextlib.contextmanager
def temporary_suspend(self):
with self._lock:
log_manager = Manager(
self,
self._output,
ensure_newline=self._ensure_newline,
)
self._output = None
try:
yield log_manager
finally:
log_manager.resume()

def _writeline(self, line: str) -> None:
if self._ensure_newline:
print(file=self._output)
self._ensure_newline = False
print(line, file=self._output)

def _flush_buffer(self) -> None:
if self._buffer:
for line in self._buffer:
self._writeline(line)
self._buffer = []


class Logger:
"""
legacy class responsible for printing to console,
will be replaced by standard python logging
"""

def __init__(self, writer: LineLogger):
self._writer = writer

def writeline(self, line: str) -> None:
self._writer.writeline(line)

def log_service_line(self, line: str) -> None:
"""Log service output line."""
self.writeline(line)

def log_entry(self, entry: dict) -> None:
"""Log simple key-value entry."""
line = tskv.dict_to_tskv(entry, add_header=False)
self.writeline(line)


class ColoredLevelFormatter(logging.Formatter):
LEVEL_COLORS = {
logging.DEBUG: colors.Colors.GRAY,
logging.INFO: colors.Colors.BRIGHT_GREEN,
logging.WARNING: colors.Colors.YELLOW,
logging.ERROR: colors.Colors.RED,
logging.CRITICAL: colors.Colors.BRIGHT_RED,
}

def __init__(self, *, colors_enabled=False):
super().__init__()
self._colors_enabled = colors_enabled

def format(self, record: logging.LogRecord):
message = super().format(record)
if not self._colors_enabled:
return f'{record.levelname} {message}'
color = self.LEVEL_COLORS.get(record.levelno, colors.Colors.DEFAULT)
return f'{color}{record.levelname}{colors.Colors.DEFAULT} {message}'


class Handler(logging.Handler):
def __init__(self, *, writer: Logger, level=logging.NOTSET):
super().__init__(level)
self._writer = writer

def emit(self, record):
if hasattr(record, 'tskv'):
self._writer.log_entry(
{**record.tskv, 'text': record.msg, 'level': record.levelname},
)
else:
message = self.format(record)
self._writer.writeline(message)
Loading

0 comments on commit cc74826

Please sign in to comment.