diff --git a/app/console.py b/app/console.py new file mode 100644 index 0000000..a4e5489 --- /dev/null +++ b/app/console.py @@ -0,0 +1,107 @@ +"""Читаемый вывод в консоли: цвета и перенос длинных строк. + +Windows-консоль по умолчанию не разбирает ANSI-последовательности и печатает +их как мусор вида `[34mINFO[0m`. Начиная с Windows 10 разбор можно включить +через WinAPI - это и делается ниже. Если включить не удалось (старая система, +вывод перенаправлен в файл), цвета молча отключаются: лучше блёклый лог, +чем лог с мусором. +""" +import logging +import os +import shutil +import sys +import textwrap +from collections.abc import Callable + +__all__ = ["enable_ansi", "ConsoleFormatter", "setup_logging"] + +# Цвет только там, где он несёт смысл: обычные сообщения остаются обычными, +# чтобы предупреждения и ошибки было видно с одного взгляда. +COLORS = { + "DEBUG": "\033[90m", + "INFO": "", + "WARNING": "\033[33m", + "ERROR": "\033[31m", + "CRITICAL": "\033[1;31m", +} +DIM = "\033[90m" +RESET = "\033[0m" +MIN_WIDTH = 60 +FALLBACK_WIDTH = 100 + + +def enable_ansi() -> bool: + """Включает разбор ANSI в консоли Windows. Возвращает, можно ли красить.""" + if not sys.stdout.isatty(): + return False + if os.name != "nt": + return True + try: + import ctypes + + kernel32 = ctypes.windll.kernel32 + handle = kernel32.GetStdHandle(-11) # STD_OUTPUT_HANDLE + mode = ctypes.c_uint32() + if not kernel32.GetConsoleMode(handle, ctypes.byref(mode)): + return False + # ENABLE_VIRTUAL_TERMINAL_PROCESSING + return bool(kernel32.SetConsoleMode(handle, mode.value | 0x0004)) + except (ImportError, AttributeError, OSError): + return False + + +def console_width() -> int: + """Ширина окна консоли. При перенаправлении в файл берём разумную по умолчанию.""" + width = shutil.get_terminal_size((FALLBACK_WIDTH, 24)).columns + return max(MIN_WIDTH, width) + + +class ConsoleFormatter(logging.Formatter): + """Формат вида `09:29:46 WARNING текст`, длинные строки переносятся по словам. + + Продолжение переносится с отступом под текст сообщения, а не под начало + строки: так видно, где кончается одно сообщение и начинается следующее. + """ + + def __init__(self, colored: bool, + width: Callable[[], int] = console_width) -> None: + super().__init__(datefmt="%H:%M:%S") + self.colored = colored + # Ширину берём через переданную функцию, а не из глобальной: окно консоли + # меняется на ходу, а в тестах ширину надо задавать явно. + self.width = width + + def format(self, record: logging.LogRecord) -> str: + stamp = self.formatTime(record, self.datefmt) + level = record.levelname + head = f"{stamp} {level:<8}" + indent = " " * len(head) + body = record.getMessage() + if record.exc_info: + body = f"{body}\n{self.formatException(record.exc_info)}" + + lines: list[str] = [] + room = self.width() - len(head) + for chunk in body.splitlines() or [""]: + lines.extend(textwrap.wrap(chunk, width=room) or [""]) + + if not self.colored: + return "\n".join([head + lines[0]] + + [indent + line for line in lines[1:]]) + + tint = COLORS.get(level, "") + painted = f"{DIM}{stamp}{RESET} {tint}{level:<8}{RESET}" if tint \ + else f"{DIM}{stamp}{RESET} {level:<8}" + return "\n".join([painted + lines[0]] + + [indent + line for line in lines[1:]]) + + +def setup_logging(level: int = logging.INFO) -> bool: + """Настраивает единый обработчик вывода. Возвращает, включены ли цвета.""" + colored = enable_ansi() + handler = logging.StreamHandler(sys.stdout) + handler.setFormatter(ConsoleFormatter(colored)) + root = logging.getLogger() + root.handlers[:] = [handler] + root.setLevel(level) + return colored diff --git a/app/main.py b/app/main.py index 8c07bc7..faca491 100644 --- a/app/main.py +++ b/app/main.py @@ -16,6 +16,7 @@ from fastapi.responses import JSONResponse from fastapi.security import HTTPBearer from app.config import ConfigError, Settings, load_settings +from app.console import setup_logging from app.logbuffer import get as log_buffer from app.logbuffer import install as install_log_buffer from app.pipeline import ModelsMissing, Pipeline, to_wav16k @@ -390,8 +391,7 @@ def run() -> None: _setup_console() install_log_buffer() - logging.basicConfig(level=logging.INFO, - format="%(asctime)s %(levelname)s %(name)s: %(message)s") + colored = setup_logging(logging.INFO) if not settings.token: print("\n В config.toml пустой токен - сервис никого не пустит." @@ -414,9 +414,10 @@ def run() -> None: f"\n Потоков: {settings.effective_threads()}" f"\n Проверка: curl http://localhost:{settings.port}/health" "\n Остановить: Ctrl+C\n") - # Windows-консоль не разбирает ANSI-последовательности и печатает их как мусор + # Красим только если разбор ANSI удалось включить: иначе консоль напечатает + # сами последовательности вместо цвета. uvicorn.run(app, host=settings.host, port=settings.port, log_level="info", - use_colors=(os.name != "nt")) + use_colors=colored) if __name__ == "__main__": diff --git a/build/make_windows_zip.py b/build/make_windows_zip.py index cc38963..b677c11 100644 --- a/build/make_windows_zip.py +++ b/build/make_windows_zip.py @@ -141,9 +141,9 @@ chcp 65001 >nul cd /d "%~dp0" set "TALKSCORE_ASR_HOME=%~dp0" set "PYTHONPATH=%~dp0" -start "talkscore-asr" /min "%~dp0python\\python.exe" -m app.main -timeout /t 5 /nobreak >nul -"%~dp0bin\\caddy.exe" run --config "%~dp0Caddyfile" +start "caddy" /min "%~dp0bin\\caddy.exe" run --config "%~dp0Caddyfile" +"%~dp0python\\python.exe" -m app.updater +"%~dp0python\\python.exe" -m app.main pause """ @@ -151,6 +151,20 @@ CADDYFILE = """# Домены, на которых отвечает сервис # Let's Encrypt и будет продлевать их без напоминаний. # Требуется: порты 80 и 443 открыты снаружи, домены указывают на эту машину. +{ + # Caddy очень подробно рассказывает про сертификаты и забивает консоль, из-за + # чего не видно сообщений самого сервиса. Уводим его вывод в файл: история + # сохраняется целиком, а на экране остаётся только talkscore-asr. + log { + output file logs/caddy.log { + roll_size 10MiB + roll_keep 5 + } + format console + level INFO + } +} + asr.netranking.ru, asr.talkscore.ru { reverse_proxy 127.0.0.1:8756 { # Реальный адрес клиента - иначе список разрешённых адресов diff --git a/tests/test_console.py b/tests/test_console.py new file mode 100644 index 0000000..1f62a6d --- /dev/null +++ b/tests/test_console.py @@ -0,0 +1,75 @@ +"""Проверки читаемости консольного вывода.""" +import logging +import sys +from unittest.mock import patch + +from app.console import ConsoleFormatter, enable_ansi, setup_logging + + +def record(level: int, message: str) -> logging.LogRecord: + return logging.LogRecord("talkscore-asr", level, __file__, 1, message, None, None) + + +class TestWrapping: + def test_short_message_stays_on_one_line(self): + out = ConsoleFormatter(colored=False).format(record(logging.INFO, "готово")) + assert out.count("\n") == 0 + assert out.endswith("готово") + + def test_long_message_wraps(self): + out = ConsoleFormatter(colored=False, width=lambda: 80).format( + record(logging.INFO, "слово " * 60)) + assert out.count("\n") >= 1 + assert all(len(line) <= 80 for line in out.splitlines()) + + def test_continuation_aligned_under_message(self): + """Перенос идёт под текст, а не под начало строки - так видно границу сообщений.""" + out = ConsoleFormatter(colored=False, width=lambda: 70).format( + record(logging.WARNING, "слово " * 40)) + first, second = out.splitlines()[:2] + head = len(first) - len(first.lstrip()) + first.index("слово") + assert second.startswith(" " * head) + assert second.lstrip()[0] != " " + + def test_existing_newlines_are_kept(self): + out = ConsoleFormatter(colored=False).format( + record(logging.INFO, "первая\nвторая")) + assert "первая" in out.splitlines()[0] + assert "вторая" in out.splitlines()[1] + + +class TestColour: + def test_no_escape_codes_when_colour_off(self): + """Главное требование: без цвета в выводе не должно быть ANSI-мусора.""" + for level in (logging.INFO, logging.WARNING, logging.ERROR): + out = ConsoleFormatter(colored=False).format(record(level, "текст")) + assert "\033" not in out + + def test_warning_and_error_are_painted(self): + for level in (logging.WARNING, logging.ERROR): + out = ConsoleFormatter(colored=True).format(record(level, "текст")) + assert "\033[" in out + + def test_info_level_is_not_painted(self): + """Обычные сообщения остаются неокрашенными, иначе цвет перестаёт что-то значить.""" + out = ConsoleFormatter(colored=True).format(record(logging.INFO, "текст")) + assert "\033[3" not in out # ни жёлтого, ни красного + + +class TestAnsiDetection: + def test_disabled_when_output_is_redirected(self): + """Перенаправленный в файл вывод красить нельзя - в файл попадут коды.""" + with patch.object(sys.stdout, "isatty", return_value=False): + assert enable_ansi() is False + + +class TestSetup: + def test_setup_replaces_handlers(self): + root = logging.getLogger() + before = root.handlers[:] + try: + setup_logging(logging.INFO) + assert len(root.handlers) == 1 + assert isinstance(root.handlers[0].formatter, ConsoleFormatter) + finally: + root.handlers[:] = before