From f89338e0158780d97436539751e81aa99c78f768 Mon Sep 17 00:00:00 2001 From: Lacky1234union Date: Sat, 17 Oct 2026 14:49:02 +0300 Subject: [PATCH] =?UTF-8?q?feat(logs):=20=D1=80=D0=B0=D0=B7=D0=B4=D0=B5?= =?UTF-8?q?=D0=BB=20=C2=AB=D0=9B=D0=BE=D0=B3=D0=B8=C2=BB=20=E2=80=94=20?= =?UTF-8?q?=D1=85=D0=B2=D0=BE=D1=81=D1=82=20=D0=B8=20=D1=81=D0=B2=D0=BE?= =?UTF-8?q?=D0=B9=20grep=20(#16)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit - app/logs/grep.py: подмножество grep (шаблон, -i -v -E -c -C N), разбор shlex без исполнения, BRE → regex, таймаут на строку и бюджет на поиск, лимиты 200 символов / 500 строк вывода - app/logs/journal.py: каждый поиск в log_queries (L-6) - бот: выбор контейнера, хвост 50/200 строк или 5 мин/1 ч/24 ч, свой grep по 24 ч, длинный результат — файлом .log (L-5) - логи Docker: не больше 50 000 строк и 5 МБ, сохраняются новейшие - fix: кнопки меню и /menu, /help больше не проглатываются шагами ввода (имя файла, содержимое, сообщение коммита, grep) — фильтр free_input Co-Authored-By: Claude Opus 5.5 --- app/bot/menu.py | 8 ++ app/bot/routers/commit.py | 10 +- app/bot/routers/common.py | 1 - app/bot/routers/logs.py | 234 ++++++++++++++++++++++++++++++++++ app/config.py | 2 + app/logs/__init__.py | 1 + app/logs/grep.py | 201 +++++++++++++++++++++++++++++ app/logs/journal.py | 15 +++ app/main.py | 4 +- app/runtime/docker.py | 39 +++--- app/texts.py | 33 ++++- config/texts.yaml | 38 +++++- tests/bot/test_commit_edit.py | 12 ++ tests/bot/test_common.py | 2 +- tests/bot/test_logs.py | 159 +++++++++++++++++++++++ tests/logs/__init__.py | 0 tests/logs/test_grep.py | 151 ++++++++++++++++++++++ tests/runtime/fake_docker.py | 3 +- 18 files changed, 884 insertions(+), 29 deletions(-) create mode 100644 app/bot/routers/logs.py create mode 100644 app/logs/__init__.py create mode 100644 app/logs/grep.py create mode 100644 app/logs/journal.py create mode 100644 tests/bot/test_logs.py create mode 100644 tests/logs/__init__.py create mode 100644 tests/logs/test_grep.py diff --git a/app/bot/menu.py b/app/bot/menu.py index c13f9b0..9339737 100644 --- a/app/bot/menu.py +++ b/app/bot/menu.py @@ -2,9 +2,11 @@ from enum import StrEnum +from aiogram import F from aiogram.filters.callback_data import CallbackData from aiogram.types import InlineKeyboardMarkup, ReplyKeyboardMarkup from aiogram.utils.keyboard import InlineKeyboardBuilder, ReplyKeyboardBuilder +from magic_filter import MagicFilter from app.texts import Texts @@ -38,6 +40,12 @@ def section_by_button(texts: Texts) -> dict[str, Section]: } +def free_input(texts: Texts) -> MagicFilter: + """Input for a dialog step — anything but a main-menu button or a bot command: those must work from any step, + otherwise «🩺 Статус» pressed while the bot waits for a file name becomes the file name.""" + return ~F.text.in_(set(section_by_button(texts))) & ~F.text.regexp(r"^/(start|menu|help)(@\w+)?(\s|$)") + + def main_menu(texts: Texts, *, is_admin: bool) -> ReplyKeyboardMarkup: m = texts.menu kb = ReplyKeyboardBuilder() diff --git a/app/bot/routers/commit.py b/app/bot/routers/commit.py index 3466f33..3b720d0 100644 --- a/app/bot/routers/commit.py +++ b/app/bot/routers/commit.py @@ -16,7 +16,7 @@ from aiogram.fsm.state import State, StatesGroup from aiogram.types import BufferedInputFile, CallbackQuery, InlineKeyboardMarkup, Message from aiogram.utils.keyboard import InlineKeyboardBuilder -from app.bot.menu import Nav, NavAction +from app.bot.menu import Nav, NavAction, free_input from app.db.models import ChangeOp, User from app.repo.drafts import DraftFull, DraftService, DraftView from app.repo.git import Entry, GitError, UploadsRepo @@ -520,7 +520,7 @@ def build_router( # ---- text input -------------------------------------------------------------------------------------------- - @router.message(Flow.file_name, F.text) + @router.message(Flow.file_name, F.text, free_input(texts)) async def got_file_name(message: Message, state: FSMContext, member: User) -> None: data = await state.get_data() directory = data.get("commit_path", "") @@ -541,7 +541,7 @@ def build_router( await state.update_data(commit_target=path, commit_op=ChangeOp.ADD.value) await message.answer(t.ask_content.format(path=path), reply_markup=to_dir_keyboard(texts)) - @router.message(Flow.dir_name, F.text) + @router.message(Flow.dir_name, F.text, free_input(texts)) async def got_dir_name(message: Message, state: FSMContext, member: User) -> None: data = await state.get_data() directory = data.get("commit_path", "") @@ -562,7 +562,7 @@ def build_router( text, kb = await dir_screen(state, member.tg_id, path, 0) await message.answer(text, reply_markup=kb) - @router.message(Flow.message, F.text) + @router.message(Flow.message, F.text, free_input(texts)) async def got_message(message: Message, state: FSMContext, member: User) -> None: try: text = check_message(message.text or "") @@ -579,7 +579,7 @@ def build_router( screen, kb = await draft_screen(state, member.tg_id) await message.answer(screen, reply_markup=kb) - @router.message(Flow.content, F.text | F.document) + @router.message(Flow.content, F.text | F.document, free_input(texts)) async def got_content(message: Message, state: FSMContext, member: User, bot: Bot) -> None: data = await state.get_data() target: str = data["commit_target"] diff --git a/app/bot/routers/common.py b/app/bot/routers/common.py index 439a03f..e5afa5f 100644 --- a/app/bot/routers/common.py +++ b/app/bot/routers/common.py @@ -16,7 +16,6 @@ def build_router(texts: Texts, access: AccessService) -> Router: router = Router(name="common") sections = section_by_button(texts) section_text = { - Section.LOGS: texts.section.logs, Section.ALERTS: texts.section.alerts, } diff --git a/app/bot/routers/logs.py b/app/bot/routers/logs.py new file mode 100644 index 0000000..e6522c7 --- /dev/null +++ b/app/bot/routers/logs.py @@ -0,0 +1,234 @@ +"""«📜 Логи»: pick a container, then its tail or your own grep (SPEC L-1…L-3, L-5, L-6). The agent is #18.""" + +import asyncio +import html +import logging +from datetime import timedelta +from enum import StrEnum + +from aiogram import F, Router +from aiogram.enums import ParseMode +from aiogram.filters.callback_data import CallbackData +from aiogram.fsm.context import FSMContext +from aiogram.fsm.state import State, StatesGroup +from aiogram.types import BufferedInputFile, CallbackQuery, InlineKeyboardMarkup, Message +from aiogram.utils.keyboard import InlineKeyboardBuilder + +from app.bot.menu import Nav, NavAction, free_input +from app.db.models import LogMode, User, utcnow +from app.logs.grep import GrepError, GrepErrorCode, GrepResult, parse_grep, run, to_command +from app.logs.journal import LogJournal +from app.runtime.docker import Container, DockerClient, DockerError +from app.texts import LogsTexts, Texts + +log = logging.getLogger(__name__) + +TAILS = (50, 200) # lines (L-2) +PERIODS = (5, 60, 24 * 60) # minutes (L-2) +GREP_WINDOW = timedelta(hours=24) +MAX_MESSAGE = 3500 # leave room under Telegram's 4096 for the header and HTML markup +MAX_FILE = 5 * 1024 * 1024 # L-5 + + +class LogsAct(StrEnum): + LIST = "l" + OPEN = "o" + TAIL = "t" + SINCE = "s" + GREP = "g" + AGENT = "a" + + +class LogsCb(CallbackData, prefix="lg"): + a: LogsAct + id: str = "" # 12-char container id prefix + n: int = 0 # lines for TAIL, minutes for SINCE + + +class LogsFlow(StatesGroup): + grep = State() + + +def period(t: LogsTexts, minutes: int) -> str: + return t.hours.format(n=minutes // 60) if minutes >= 60 else t.minutes.format(n=minutes) + + +def list_keyboard(texts: Texts, containers: list[Container]) -> InlineKeyboardMarkup: + kb = InlineKeyboardBuilder() + for c in containers: + kb.button(text=f"{c.light.value} {c.name}", callback_data=LogsCb(a=LogsAct.OPEN, id=c.short_id)) + kb.button(text=texts.menu.back, callback_data=Nav(action=NavAction.BACK)) + kb.adjust(1) + return kb.as_markup() + + +def container_keyboard(texts: Texts, short_id: str) -> InlineKeyboardMarkup: + t = texts.logs + kb = InlineKeyboardBuilder() + for n in TAILS: + kb.button(text=t.tail.format(n=n), callback_data=LogsCb(a=LogsAct.TAIL, id=short_id, n=n)) + for minutes in PERIODS: + kb.button(text=period(t, minutes), callback_data=LogsCb(a=LogsAct.SINCE, id=short_id, n=minutes)) + kb.button(text=t.grep_button, callback_data=LogsCb(a=LogsAct.GREP, id=short_id)) + kb.button(text=t.agent_button, callback_data=LogsCb(a=LogsAct.AGENT, id=short_id)) + kb.button(text=t.to_list, callback_data=LogsCb(a=LogsAct.LIST)) + kb.adjust(2, 3, 2, 1) + return kb.as_markup() + + +def notes(t: LogsTexts, result: GrepResult) -> list[str]: + out = [] + if result.truncated: + out.append(t.truncated.format(n=len(result.lines))) + if result.partial: + out.append(t.partial) + if result.skipped: + out.append(t.skipped.format(n=result.skipped)) + return out + + +def grep_error(t: LogsTexts, e: GrepError) -> str: + template = { + GrepErrorCode.EMPTY: t.err_empty, + GrepErrorCode.QUOTES: t.err_quotes, + GrepErrorCode.FLAG: t.err_flag, + GrepErrorCode.CONTEXT: t.err_context, + GrepErrorCode.EXTRA: t.err_extra, + GrepErrorCode.TOO_LONG: t.err_too_long, + GrepErrorCode.REGEX: t.err_regex, + }[e.code] + return template.format(arg=html.escape(e.arg[:100])) + + +async def send_result( + msg: Message, texts: Texts, head: str, body: str, footer: list[str], kb: InlineKeyboardMarkup, filename: str +) -> None: + """Short results inline as
, long ones as a .log document (L-5); the container keyboard rides along."""
+    t = texts.logs
+    tail = "".join(f"\n{html.escape(n)}" for n in footer)
+    if not body:
+        await msg.answer(f"{head}\n{t.nothing}{tail}", parse_mode=ParseMode.HTML, reply_markup=kb)
+        return
+    escaped = html.escape(body)
+    if len(escaped) <= MAX_MESSAGE:
+        await msg.answer(f"{head}\n
{escaped}
{tail}", parse_mode=ParseMode.HTML, reply_markup=kb) + return + data = body.encode()[-MAX_FILE:] + await msg.answer_document( + BufferedInputFile(data, filename), + caption=f"{head}\n{t.sent_as_file}{tail}", + parse_mode=ParseMode.HTML, + reply_markup=kb, + ) + + +def build_router(texts: Texts, docker: DockerClient | None, journal: LogJournal) -> Router: + router = Router(name="logs") + t = texts.logs + + def need_docker() -> DockerClient: + if docker is None: + raise DockerError("docker is not configured (DOCKER_URL)") + return docker + + @router.message(F.text == texts.menu.logs) + async def open_logs(message: Message, state: FSMContext) -> None: + await state.clear() + try: + containers = await need_docker().containers() + except DockerError as e: + log.warning("logs: %s", e) + await message.answer(t.unavailable) + return + await message.answer(t.title if containers else t.empty, reply_markup=list_keyboard(texts, containers)) + + @router.callback_query(LogsCb.filter()) + async def on_action(query: CallbackQuery, callback_data: LogsCb, state: FSMContext, member: User) -> None: + if not isinstance(query.message, Message): + await query.answer() + return + msg = query.message + try: + d = need_docker() + if callback_data.a is LogsAct.LIST: + await state.clear() + containers = await d.containers() + await msg.edit_text(t.title if containers else t.empty, reply_markup=list_keyboard(texts, containers)) + await query.answer() + return + c = await d.get(callback_data.id) + kb = container_keyboard(texts, c.short_id) + match callback_data.a: + case LogsAct.OPEN: + await state.clear() + await msg.edit_text(t.container.format(name=c.name), reply_markup=kb) + case LogsAct.TAIL | LogsAct.SINCE: + await query.answer() + if callback_data.a is LogsAct.TAIL: + n = min(max(callback_data.n, 1), max(TAILS)) + text = await d.logs(c.id, tail=n) + scope, q = t.tail.format(n=n), {"tail": n} + else: + minutes = min(max(callback_data.n, 1), max(PERIODS)) + text = await d.logs(c.id, since=utcnow() - timedelta(minutes=minutes)) + scope, q = t.since.format(period=period(t, minutes)), {"since_minutes": minutes} + lines = text.splitlines() + await journal.record(member.tg_id, c.name, LogMode.TAIL, q, len(lines)) + head = t.head_tail.format(name=html.escape(c.name), scope=scope, lines=len(lines)) + await send_result(msg, texts, head, "\n".join(lines), [], kb, f"{c.name}.log") + return + case LogsAct.GREP: + await state.set_state(LogsFlow.grep) + await state.update_data(logs_id=c.short_id) + back = InlineKeyboardBuilder() + back.button(text=t.to_container, callback_data=LogsCb(a=LogsAct.OPEN, id=c.short_id)) + await msg.answer( + t.ask_grep.format(name=html.escape(c.name)), + parse_mode=ParseMode.HTML, + reply_markup=back.as_markup(), + ) + case LogsAct.AGENT: + await query.answer(t.agent_soon, show_alert=True) + return + except DockerError as e: + log.warning("logs: %s", e) + await query.answer(t.unavailable, show_alert=True) + return + await query.answer() + + @router.message(LogsFlow.grep, F.text, free_input(texts)) + async def got_grep(message: Message, state: FSMContext, member: User) -> None: + try: + query = parse_grep(message.text or "") + except GrepError as e: + await message.answer(grep_error(t, e), parse_mode=ParseMode.HTML) + return # stay in the state: fix and resend + data = await state.get_data() + try: + d = need_docker() + c = await d.get(data.get("logs_id", "")) + text = await d.logs(c.id, since=utcnow() - GREP_WINDOW) + except DockerError as e: + log.warning("logs: %s", e) + await message.answer(t.unavailable) + return + await state.clear() + result = await asyncio.to_thread(run, query, text) + await journal.record(member.tg_id, c.name, LogMode.GREP, query.to_dict(), result.matched) + head = t.head_grep.format( + command=html.escape(to_command(query)), name=html.escape(c.name), matched=result.matched + ) + body = "" if query.count else "\n".join(result.lines) + footer = notes(t, result) + if query.count: # -c: the number in the header is the answer + await message.answer( + head + "".join(f"\n{html.escape(n)}" for n in footer), + parse_mode=ParseMode.HTML, + reply_markup=container_keyboard(texts, c.short_id), + ) + return + await send_result( + message, texts, head, body, footer, container_keyboard(texts, c.short_id), f"{c.name}-grep.log" + ) + + return router diff --git a/app/config.py b/app/config.py index 35122bd..4dd40ad 100644 --- a/app/config.py +++ b/app/config.py @@ -93,7 +93,9 @@ class DockerSettings(BaseSettings): label: str = "tgit.managed=true" timeout: float = Field(default=10.0, gt=0) snapshot_interval: float = Field(default=15.0, gt=0) + # One logs request reads at most this much (SPEC L-5: 5 MB); the newest lines win max_log_bytes: int = Field(default=5 * 1024 * 1024, gt=0) + max_log_lines: int = Field(default=50_000, gt=0) class RuntimeSettings(BaseSettings): diff --git a/app/logs/__init__.py b/app/logs/__init__.py new file mode 100644 index 0000000..0642cb3 --- /dev/null +++ b/app/logs/__init__.py @@ -0,0 +1 @@ +"""Log search: a grep subset executed in Python, never in a shell (ARCHITECTURE §2.7).""" diff --git a/app/logs/grep.py b/app/logs/grep.py new file mode 100644 index 0000000..1aa45e4 --- /dev/null +++ b/app/logs/grep.py @@ -0,0 +1,201 @@ +"""`grep` for logs: parse a grep-like expression, run it with the `regex` module, show it back as a command. + +Nothing here executes anything: `shlex.split` only tokenizes, the pattern goes to `regex` with a per-line timeout +and an overall time budget, so `(a+)+$` on a long line costs at most the budget, not the bot. +Supported: PATTERN, -i, -v, -E, -c, -C N (also -C2, -iv, `--`, a leading `grep`). Anything else is an error. +""" + +import shlex +import time +from dataclasses import asdict, dataclass, field +from enum import StrEnum +from typing import Any + +import regex + +MAX_PATTERN = 200 +MAX_CONTEXT = 10 +MAX_LINES = 500 # output lines, context and `--` separators included +LINE_TIMEOUT = 0.05 # seconds per line +BUDGET = 3.0 # seconds per search; on overrun the result is partial and says so + +_BRE_SPECIAL = set("+?|(){}") + + +class GrepErrorCode(StrEnum): + EMPTY = "empty" + QUOTES = "quotes" + FLAG = "flag" + CONTEXT = "context" + EXTRA = "extra" + TOO_LONG = "too_long" + REGEX = "regex" + + +class GrepError(ValueError): + def __init__(self, code: GrepErrorCode, arg: str = "") -> None: + super().__init__(f"{code}: {arg}" if arg else code.value) + self.code = code + self.arg = arg + + +@dataclass(frozen=True) +class GrepQuery: + pattern: str + ignore_case: bool = False + invert: bool = False + extended: bool = False + count: bool = False + context: int = 0 + + def to_dict(self) -> dict[str, Any]: + return asdict(self) + + def compile(self) -> "regex.Pattern[str]": + source = self.pattern if self.extended else bre_to_ere(self.pattern) + try: + return regex.compile(source, regex.IGNORECASE if self.ignore_case else 0) + except regex.error as e: + raise GrepError(GrepErrorCode.REGEX, str(e)) from e + + +def bre_to_ere(pattern: str) -> str: + """Basic grep regex → Python: without -E `+ ? | ( ) { }` are literals and `\\+` etc. are the operators.""" + out: list[str] = [] + i, in_class = 0, False + while i < len(pattern): + ch = pattern[i] + if in_class: + out.append(ch) + if ch == "]" and not (out[-2:-1] == ["["] or out[-3:-1] == ["[", "^"]): + in_class = False + elif ch == "[": + in_class = True + out.append(ch) + elif ch == "\\" and i + 1 < len(pattern): + nxt = pattern[i + 1] + out.append(nxt if nxt in _BRE_SPECIAL else ch + nxt) + i += 1 + elif ch in _BRE_SPECIAL: + out.append("\\" + ch) + else: + out.append(ch) + i += 1 + return "".join(out) + + +def _context(value: str) -> int: + if not value.isdigit() or int(value) > MAX_CONTEXT: + raise GrepError(GrepErrorCode.CONTEXT, value) + return int(value) + + +def parse_grep(expr: str) -> GrepQuery: + try: + tokens = shlex.split(expr) + except ValueError as e: + raise GrepError(GrepErrorCode.QUOTES) from e + if tokens[:1] == ["grep"]: + tokens = tokens[1:] + opts: dict[str, Any] = {} + patterns: list[str] = [] + i = 0 + while i < len(tokens): + tok = tokens[i] + if patterns or tok == "--" or not tok.startswith("-") or tok == "-": + if tok == "--" and not patterns: + patterns.extend(tokens[i + 1 :]) + break + patterns.append(tok) + elif tok.startswith("-C"): + if len(tok) > 2: + opts["context"] = _context(tok[2:]) + elif i + 1 < len(tokens): + opts["context"] = _context(tokens[i + 1]) + i += 1 + else: + raise GrepError(GrepErrorCode.CONTEXT, "") + else: + for j, flag in enumerate(tok[1:], start=1): + match flag: + case "i": + opts["ignore_case"] = True + case "v": + opts["invert"] = True + case "E": + opts["extended"] = True + case "c": + opts["count"] = True + case "C" if tok[j + 1 :].isdigit(): + opts["context"] = _context(tok[j + 1 :]) + break + case _: + raise GrepError(GrepErrorCode.FLAG, f"-{flag}") + i += 1 + if not patterns or not patterns[0]: + raise GrepError(GrepErrorCode.EMPTY) + if len(patterns) > 1: + raise GrepError(GrepErrorCode.EXTRA, patterns[1]) + if len(patterns[0]) > MAX_PATTERN: + raise GrepError(GrepErrorCode.TOO_LONG, str(len(patterns[0]))) + query = GrepQuery(pattern=patterns[0], **opts) + query.compile() # syntax errors now, not halfway through the logs + return query + + +def to_command(query: GrepQuery) -> str: + """The query as a shell-looking line, for the user to see what was searched (SPEC L-15).""" + flags = "".join( + f for f, on in (("i", query.ignore_case), ("v", query.invert), ("E", query.extended), ("c", query.count)) if on + ) + parts = ["grep"] + if flags: + parts.append(f"-{flags}") + if query.context: + parts += ["-C", str(query.context)] + if query.pattern.startswith("-"): + parts.append("--") + parts.append(shlex.quote(query.pattern)) + return " ".join(parts) + + +@dataclass +class GrepResult: + lines: list[str] = field(default_factory=list) + matched: int = 0 + truncated: bool = False # more output than MAX_LINES + partial: bool = False # time budget ran out: not every line was searched + skipped: int = 0 # lines where the pattern hit the per-line timeout + + +def run(query: GrepQuery, text: str, max_lines: int = MAX_LINES, budget: float = BUDGET) -> GrepResult: + pattern = query.compile() + lines = text.splitlines() + result = GrepResult() + deadline = time.monotonic() + budget + last_emitted = -1 # index of the last line already in the output (for context merging) + for n, line in enumerate(lines): + if time.monotonic() > deadline: + result.partial = True + break + try: + hit = pattern.search(line, timeout=LINE_TIMEOUT) is not None + except TimeoutError: + result.skipped += 1 + continue + if hit == query.invert: + continue + result.matched += 1 + if query.count or result.truncated: + continue + start = max(n - query.context, last_emitted + 1) + if query.context and result.lines and start > last_emitted + 1: + result.lines.append("--") + end = min(n + query.context, len(lines) - 1) + for k in range(start, end + 1): + if len(result.lines) >= max_lines: + result.truncated = True + break + result.lines.append(lines[k]) + last_emitted = k + return result diff --git a/app/logs/journal.py b/app/logs/journal.py new file mode 100644 index 0000000..5060b74 --- /dev/null +++ b/app/logs/journal.py @@ -0,0 +1,15 @@ +"""Every log search is recorded: who, which container, what, how many lines came back (SPEC L-6).""" + +from typing import Any + +from app.db.models import LogMode, LogQuery +from app.db.session import SessionMaker + + +class LogJournal: + def __init__(self, sessions: SessionMaker) -> None: + self._sessions = sessions + + async def record(self, user_id: int, container: str, mode: LogMode, query: dict[str, Any], lines: int) -> None: + async with self._sessions.begin() as session: + session.add(LogQuery(user_id=user_id, container=container, mode=mode, query=query, lines=lines)) diff --git a/app/main.py b/app/main.py index 352714d..06f2ee0 100644 --- a/app/main.py +++ b/app/main.py @@ -11,12 +11,13 @@ from app import __version__ from app.access.service import AccessService from app.bot.fsm import make_storage from app.bot.middlewares.access import AccessMiddleware -from app.bot.routers import commit, common, members, status +from app.bot.routers import commit, common, logs, members, status from app.config import Settings from app.db.maintenance import cleanup_loop from app.db.migrate import upgrade from app.db.session import SessionMaker, make_engine, make_sessionmaker from app.health import heartbeat +from app.logs.journal import LogJournal from app.logs_setup import setup_logging from app.repo.drafts import DraftService from app.repo.git import UploadsRepo @@ -48,6 +49,7 @@ def build_dispatcher( commit.build_router(texts, repo, DraftService(sessions), Publisher(repo, sessions), commit_url_template) ) dp.include_router(status.build_router(texts, docker, checker)) + dp.include_router(logs.build_router(texts, docker, LogJournal(sessions))) dp.include_router(common.build_router(texts, access)) return dp diff --git a/app/runtime/docker.py b/app/runtime/docker.py index 3fcaa7b..64ab0f5 100644 --- a/app/runtime/docker.py +++ b/app/runtime/docker.py @@ -171,7 +171,7 @@ class DockerClient: def __init__(self, settings: DockerSettings, transport: httpx.AsyncBaseTransport | None = None) -> None: self._s = settings self._http = httpx.AsyncClient(base_url=settings.url, timeout=settings.timeout, transport=transport) - self._known: set[str] = set() # ids from the last listing: the only ones card/logs/stats may touch + self._known: dict[str, Container] = {} # the last listing: the only ids card/logs/stats may touch async def __aenter__(self) -> Self: return self @@ -204,22 +204,22 @@ class DockerClient: labels=labels, ) ) - self._known = {c.id for c in result} + self._known = {c.id: c for c in result} return sorted(result, key=lambda c: c.name) - async def resolve(self, short_id: str) -> str: - """Full id of a managed container by its 12-char prefix (callback data carries only that).""" - if not self._known: - await self.containers() - for full in self._known: - if full.startswith(short_id): - return full - await self.containers() # maybe recreated since the last listing - for full in self._known: - if full.startswith(short_id): - return full + async def get(self, short_id: str) -> Container: + """A managed container by its 12-char id prefix (callback data carries only that).""" + for attempt in range(2): + if attempt or not self._known: + await self.containers() # first use, or recreated since the last listing + for full, container in self._known.items(): + if short_id and full.startswith(short_id): + return container raise DockerError(f"container {short_id} is not managed by tgit") + async def resolve(self, short_id: str) -> str: + return (await self.get(short_id)).id + async def inspect(self, container_id: str) -> Details: self._guard(container_id) d = await self._get_json(f"/containers/{container_id}/json") @@ -246,15 +246,18 @@ class DockerClient: return parse_stats(await self._get_json(f"/containers/{container_id}/stats", params={"stream": "false"})) async def logs(self, container_id: str, since: datetime | None = None, tail: int | None = None) -> str: + """stdout+stderr in order; at most max_log_lines lines and max_log_bytes — the newest ones are kept.""" self._guard(container_id) - params = {"stdout": "1", "stderr": "1"} + lines = min(tail, self._s.max_log_lines) if tail is not None else self._s.max_log_lines + params = {"stdout": "1", "stderr": "1", "tail": str(lines)} if since is not None: params["since"] = str(int(since.timestamp())) - if tail is not None: - params["tail"] = str(tail) response = await self._request(f"/containers/{container_id}/logs", params) - raw = response.content[: self._s.max_log_bytes] - return demux_logs(raw) + text = demux_logs(response.content) + if len(text) > self._s.max_log_bytes: + cut = text[-self._s.max_log_bytes :] + text = cut[cut.find("\n") + 1 :] # drop the torn first line + return text async def ping(self) -> bool: try: diff --git a/app/texts.py b/app/texts.py index fd30dbc..99cde01 100644 --- a/app/texts.py +++ b/app/texts.py @@ -33,7 +33,6 @@ class HelpTexts(_Strict): class SectionTexts(_Strict): commit: str - logs: str alerts: str members: str cancelled: str @@ -152,6 +151,37 @@ class StatusTexts(_Strict): seconds: str +class LogsTexts(_Strict): + title: str + empty: str + unavailable: str + container: str + tail: str + since: str + minutes: str + hours: str + grep_button: str + agent_button: str + agent_soon: str + to_list: str + to_container: str + ask_grep: str + head_tail: str + head_grep: str + nothing: str + truncated: str + partial: str + skipped: str + sent_as_file: str + err_empty: str + err_quotes: str + err_flag: str + err_context: str + err_extra: str + err_too_long: str + err_regex: str + + class Texts(_Strict): menu: MenuTexts start: StartTexts @@ -160,6 +190,7 @@ class Texts(_Strict): members: MembersTexts commit: CommitTexts status: StatusTexts + logs: LogsTexts def load_texts(config_dir: Path) -> Texts: diff --git a/config/texts.yaml b/config/texts.yaml index f8e30fa..a255c3d 100644 --- a/config/texts.yaml +++ b/config/texts.yaml @@ -30,7 +30,6 @@ help: section: commit: "📝 Коммит\n\nРаздел в разработке." - logs: "📜 Логи\n\nРаздел в разработке." alerts: "🚨 Алерты\n\nРаздел в разработке." members: "👥 Участники\n\nРаздел в разработке." cancelled: "Отменено. Главное меню — кнопками внизу." @@ -167,3 +166,40 @@ status: hours: "ч" minutes: "мин" seconds: "с" + +logs: + title: "📜 Логи · выберите контейнер" + empty: "Контейнеров tgit не найдено." + unavailable: "Docker недоступен, попробуйте через минуту." + container: |- + 📜 Логи · {name} + + Хвост, свой grep по последним 24 ч или вопрос агенту. + tail: "{n} строк" + since: "за {period}" + minutes: "{n} мин" + hours: "{n} ч" + grep_button: "🔎 Свой grep" + agent_button: "🤖 Спросить агента" + agent_soon: "Агент — в следующей версии." + to_list: "⬅️ К контейнерам" + to_container: "⬅️ К контейнеру" + ask_grep: |- + 🔎 Выражение grep — ищу по логу {name} за 24 ч. + + Например: -i -C 2 error + Флаги: -i без регистра, -v кроме, -E расширенный regex, -c только число, -C N контекст. + head_tail: "📜 {name} · {scope} · строк: {lines}" + head_grep: "🔎 {command}\n{name} · за 24 ч · совпадений: {matched}" + nothing: "Пусто." + truncated: "Показаны первые {n} строк." + partial: "Поиск остановлен по времени — просмотрена часть лога." + skipped: "Пропущено строк из-за тяжёлого шаблона: {n}." + sent_as_file: "Результат длинный — отправил файлом." + err_empty: "Нужен шаблон, например: -i error" + err_quotes: "Не закрыта кавычка." + err_flag: "Флаг {arg} не поддерживается. Можно: -i -v -E -c -C N" + err_context: "После -C нужно число от 0 до 10." + err_extra: "Нужен один шаблон, а «{arg}» лишнее. Шаблон с пробелами — в кавычках." + err_too_long: "Шаблон длиннее 200 символов." + err_regex: "Шаблон не разбирается: {arg}" diff --git a/tests/bot/test_commit_edit.py b/tests/bot/test_commit_edit.py index 47601f1..593256c 100644 --- a/tests/bot/test_commit_edit.py +++ b/tests/bot/test_commit_edit.py @@ -160,3 +160,15 @@ async def test_protected_file_cannot_be_replaced(tg: TgClient, texts: Texts, rep answer = tg.session.sent(AnswerCallbackQuery)[-1] assert answer.text == texts.commit.protected and answer.show_alert + + +@pytest.mark.parametrize("escape", ["menu_status", "/menu", "/help"]) +async def test_menu_and_commands_escape_input_states(tg: TgClient, texts: Texts, escape: str) -> None: + text = texts.menu.status if escape == "menu_status" else escape + await to_hello(tg, texts) + await tg.press(ADMIN, cb(Act.NEW_FILE)) + await tg.send(ADMIN, text) + + reply = last_text(tg) + assert reply.text != texts.commit.bad_name + assert not reply.text.startswith(texts.commit.ask_content.split("{")[0]) diff --git a/tests/bot/test_common.py b/tests/bot/test_common.py index cf28242..08f8705 100644 --- a/tests/bot/test_common.py +++ b/tests/bot/test_common.py @@ -46,7 +46,7 @@ async def test_outsider_stale_button_is_swallowed(tg: TgClient) -> None: assert len(tg.session.sent(AnswerCallbackQuery)) == 1 -@pytest.mark.parametrize("section", ["logs", "alerts"]) +@pytest.mark.parametrize("section", ["alerts"]) async def test_menu_button_opens_section_with_nav(tg: TgClient, texts: Texts, section: str) -> None: await tg.send(ADMIN, getattr(texts.menu, section)) diff --git a/tests/bot/test_logs.py b/tests/bot/test_logs.py new file mode 100644 index 0000000..bdd78af --- /dev/null +++ b/tests/bot/test_logs.py @@ -0,0 +1,159 @@ +from collections.abc import AsyncIterator + +import pytest +from aiogram.methods import AnswerCallbackQuery, EditMessageText, SendDocument, SendMessage +from sqlalchemy import select + +from app.access.service import AccessService +from app.bot.routers.logs import LogsAct, LogsCb +from app.db.models import LogMode, LogQuery +from app.db.session import SessionMaker +from app.main import build_dispatcher +from app.repo.git import UploadsRepo +from app.runtime.docker import DockerClient +from app.texts import Texts +from tests.conftest import ADMIN +from tests.fakes import TgClient +from tests.runtime.fake_docker import FakeDocker, now_minus + + +@pytest.fixture +def fake() -> FakeDocker: + fake = FakeDocker() + fake.add( + "crash", + logs=[ + (now_minus(120), "boot"), + (now_minus(30), "connect db"), + (now_minus(29), "ERROR connection refused"), + (now_minus(28), "retry"), + (now_minus(2), "html-ish & stuff"), + ], + ) + fake.add("vobot-api-1", managed=False, logs=[(now_minus(1), "SECRET")]) + return fake + + +@pytest.fixture +async def docker(fake: FakeDocker) -> AsyncIterator[DockerClient]: + async with fake.client() as client: + yield client + + +@pytest.fixture +def tg( + texts: Texts, sessions: SessionMaker, access: AccessService, repo: UploadsRepo, docker: DockerClient +) -> TgClient: + return TgClient(build_dispatcher(texts, sessions, access, repo, docker=docker)) + + +def cid(fake: FakeDocker, name: str) -> str: + return next(c.id[:12] for c in fake.containers.values() if c.name == name) + + +async def journal(sessions: SessionMaker) -> list[LogQuery]: + async with sessions() as s: + return list(await s.scalars(select(LogQuery).order_by(LogQuery.id))) + + +async def test_open_lists_only_managed(tg: TgClient, texts: Texts) -> None: + await tg.send(ADMIN, texts.menu.logs) + + [reply] = tg.session.sent(SendMessage) + assert reply.text == texts.logs.title + labels = [b.text for row in reply.reply_markup.inline_keyboard for b in row] + assert "🟢 crash" in labels and not any("vobot" in label for label in labels) + + +async def test_tail_is_escaped_and_journaled(tg: TgClient, fake: FakeDocker, sessions: SessionMaker) -> None: + await tg.press(ADMIN, LogsCb(a=LogsAct.TAIL, id=cid(fake, "crash"), n=50).pack()) + + [reply] = tg.session.sent(SendMessage) + assert "строк: 5" in reply.text + assert "<b>html-ish</b> & stuff" in reply.text + [row] = await journal(sessions) + assert (row.mode, row.container, row.query, row.lines) == (LogMode.TAIL, "crash", {"tail": 50}, 5) + + +async def test_since_period(tg: TgClient, fake: FakeDocker) -> None: + await tg.press(ADMIN, LogsCb(a=LogsAct.SINCE, id=cid(fake, "crash"), n=5).pack()) + + [reply] = tg.session.sent(SendMessage) + assert "за 5 мин · строк: 1" in reply.text + + +async def test_grep_flow(tg: TgClient, texts: Texts, fake: FakeDocker, sessions: SessionMaker) -> None: + await tg.press(ADMIN, LogsCb(a=LogsAct.GREP, id=cid(fake, "crash")).pack()) + await tg.send(ADMIN, "-i -C 1 error") + + ask, result = tg.session.sent(SendMessage) + assert ask.text.startswith("🔎 Выражение grep") + assert "grep -i -C 1 error" in result.text + assert "совпадений: 1" in result.text + assert "connect db\nERROR connection refused\nretry" in result.text + [row] = await journal(sessions) + assert row.mode is LogMode.GREP and row.query["pattern"] == "error" and row.lines == 1 + + tg.session.requests.clear() + await tg.send(ADMIN, "error") # state is cleared after one search + assert not any("совпадений" in (m.text or "") for m in tg.session.sent(SendMessage)) + + +async def test_grep_error_keeps_waiting(tg: TgClient, fake: FakeDocker) -> None: + await tg.press(ADMIN, LogsCb(a=LogsAct.GREP, id=cid(fake, "crash")).pack()) + await tg.send(ADMIN, "-r error") + await tg.send(ADMIN, "-c retry") + + _, err, result = tg.session.sent(SendMessage) + assert "Флаг -r не поддерживается" in err.text + assert "совпадений: 1" in result.text and "
" not in result.text
+
+
+async def test_grep_nothing_found(tg: TgClient, texts: Texts, fake: FakeDocker) -> None:
+    await tg.press(ADMIN, LogsCb(a=LogsAct.GREP, id=cid(fake, "crash")).pack())
+    await tg.send(ADMIN, "nope")
+
+    assert tg.session.sent(SendMessage)[-1].text.endswith(texts.logs.nothing)
+
+
+async def test_menu_button_escapes_grep_state(tg: TgClient, texts: Texts, fake: FakeDocker) -> None:
+    await tg.press(ADMIN, LogsCb(a=LogsAct.GREP, id=cid(fake, "crash")).pack())
+    await tg.send(ADMIN, texts.menu.logs)
+
+    assert tg.session.sent(SendMessage)[-1].text == texts.logs.title
+
+
+async def test_long_result_goes_as_file(tg: TgClient, fake: FakeDocker) -> None:
+    crash = next(c for c in fake.containers.values() if c.name == "crash")
+    crash.logs = [(now_minus(1), f"line {i} " + "x" * 50) for i in range(200)]
+
+    await tg.press(ADMIN, LogsCb(a=LogsAct.TAIL, id=cid(fake, "crash"), n=200).pack())
+
+    [doc] = tg.session.sent(SendDocument)
+    assert doc.document.filename == "crash.log"
+    assert doc.document.data.decode().count("\n") == 199
+
+
+async def test_foreign_container_refused(tg: TgClient, texts: Texts, fake: FakeDocker) -> None:
+    await tg.press(ADMIN, LogsCb(a=LogsAct.TAIL, id=cid(fake, "vobot-api-1"), n=50).pack())
+
+    assert not tg.session.sent(SendMessage)
+    assert tg.session.sent(AnswerCallbackQuery)[0].text == texts.logs.unavailable
+
+
+async def test_open_container_and_back_to_list(tg: TgClient, texts: Texts, fake: FakeDocker) -> None:
+    await tg.press(ADMIN, LogsCb(a=LogsAct.OPEN, id=cid(fake, "crash")).pack())
+    await tg.press(ADMIN, LogsCb(a=LogsAct.LIST).pack())
+    await tg.press(ADMIN, LogsCb(a=LogsAct.AGENT, id=cid(fake, "crash")).pack())
+
+    card, listing = tg.session.sent(EditMessageText)
+    assert card.text.startswith("📜 Логи · crash")
+    assert listing.text == texts.logs.title
+    assert tg.session.sent(AnswerCallbackQuery)[-1].text == texts.logs.agent_soon
+
+
+async def test_without_docker(texts: Texts, sessions: SessionMaker, access: AccessService, repo: UploadsRepo) -> None:
+    tg = TgClient(build_dispatcher(texts, sessions, access, repo))
+    await tg.send(ADMIN, texts.menu.logs)
+
+    assert [m.text for m in tg.session.sent(SendMessage)] == [texts.logs.unavailable]
diff --git a/tests/logs/__init__.py b/tests/logs/__init__.py
new file mode 100644
index 0000000..e69de29
diff --git a/tests/logs/test_grep.py b/tests/logs/test_grep.py
new file mode 100644
index 0000000..33fecce
--- /dev/null
+++ b/tests/logs/test_grep.py
@@ -0,0 +1,151 @@
+import time
+
+import pytest
+
+from app.logs.grep import (
+    MAX_PATTERN,
+    GrepError,
+    GrepErrorCode,
+    GrepQuery,
+    bre_to_ere,
+    parse_grep,
+    run,
+    to_command,
+)
+
+LOG = "\n".join(
+    [
+        "08:00 start",
+        "08:01 connect db",
+        "08:02 ERROR connection refused",
+        "08:03 retry",
+        "08:04 ok",
+        "08:05 idle",
+        "08:06 idle",
+        "08:07 error: timeout",
+        "08:08 done",
+    ]
+)
+
+
+@pytest.mark.parametrize(
+    ("expr", "expected"),
+    [
+        ("error", GrepQuery("error")),
+        ("grep -i error", GrepQuery("error", ignore_case=True)),
+        ("-iv 'two words'", GrepQuery("two words", ignore_case=True, invert=True)),
+        ("-E -c 'a|b'", GrepQuery("a|b", extended=True, count=True)),
+        ("-C 2 x", GrepQuery("x", context=2)),
+        ("-C2 x", GrepQuery("x", context=2)),
+        ("-iC3 x", GrepQuery("x", ignore_case=True, context=3)),
+        ("-- -v", GrepQuery("-v")),
+        ('"привет мир"', GrepQuery("привет мир")),
+    ],
+)
+def test_parse(expr: str, expected: GrepQuery) -> None:
+    assert parse_grep(expr) == expected
+
+
+@pytest.mark.parametrize(
+    ("expr", "code"),
+    [
+        ("", GrepErrorCode.EMPTY),
+        ("-i", GrepErrorCode.EMPTY),
+        ("'unclosed", GrepErrorCode.QUOTES),
+        ("-r error", GrepErrorCode.FLAG),
+        ("--include=*.py x", GrepErrorCode.FLAG),
+        ("-C x y", GrepErrorCode.CONTEXT),
+        ("-C 99 y", GrepErrorCode.CONTEXT),
+        ("-C", GrepErrorCode.CONTEXT),
+        ("error /etc/passwd", GrepErrorCode.EXTRA),
+        ("x" * (MAX_PATTERN + 1), GrepErrorCode.TOO_LONG),
+        ("-E '(unclosed'", GrepErrorCode.REGEX),
+    ],
+)
+def test_parse_errors(expr: str, code: GrepErrorCode) -> None:
+    with pytest.raises(GrepError) as e:
+        parse_grep(expr)
+    assert e.value.code is code
+
+
+def test_shell_is_never_involved() -> None:
+    # metacharacters are just pattern text
+    q = parse_grep("'$(rm -rf /); `id`'")
+    assert q.pattern == "$(rm -rf /); `id`"
+    assert to_command(q) == "grep '$(rm -rf /); `id`'"
+
+
+def test_basic_vs_extended_regex() -> None:
+    assert bre_to_ere("a+b") == r"a\+b"
+    assert bre_to_ere(r"a\+b") == "a+b"
+    assert bre_to_ere(r"\(x\|y\)") == "(x|y)"
+    assert bre_to_ere("[+?]x") == "[+?]x"
+    assert bre_to_ere("[]a]+") == r"[]a]\+"
+    assert run(parse_grep("1+1"), "1+1\n11").lines == ["1+1"]
+    assert run(parse_grep("-E 1+1"), "1+1\n11").lines == ["11"]
+
+
+def test_ignore_case_and_invert() -> None:
+    assert run(parse_grep("-i error"), LOG).lines == ["08:02 ERROR connection refused", "08:07 error: timeout"]
+    assert run(parse_grep("-v idle"), LOG).matched == 7
+
+
+def test_count() -> None:
+    result = run(parse_grep("-ci error"), LOG)
+    assert result.matched == 2
+    assert result.lines == []
+
+
+def test_context_merges_and_separates_groups() -> None:
+    result = run(parse_grep("-i -C 1 error"), LOG)
+    assert result.lines == [
+        "08:01 connect db",
+        "08:02 ERROR connection refused",
+        "08:03 retry",
+        "--",
+        "08:06 idle",
+        "08:07 error: timeout",
+        "08:08 done",
+    ]
+    overlapping = run(parse_grep("-C 2 idle"), LOG)
+    assert overlapping.lines == LOG.splitlines()[3:]  # 08:03…08:08, no duplicates, no separator
+
+
+def test_output_is_capped() -> None:
+    text = "\n".join(f"line {i}" for i in range(2000))
+    result = run(parse_grep("line"), text, max_lines=500)
+    assert len(result.lines) == 500
+    assert result.truncated
+    assert result.matched == 2000  # counting goes on
+
+
+@pytest.mark.parametrize("pattern", ["(a+)+$", "(a|aa)+$"])  # regex optimizes the first; the second really blows up
+def test_redos_does_not_hang(pattern: str) -> None:
+    evil = parse_grep(f"-E '{pattern}'")
+    text = "\n".join(["a" * 40 + "!"] * 200 + ["fine"])
+    started = time.monotonic()
+
+    result = run(evil, text, budget=1.0)
+
+    assert time.monotonic() - started < 2.0
+    assert result.matched == 0
+
+
+def test_big_input() -> None:
+    text = "\n".join(f"{i} request ok" if i % 1000 else f"{i} ERROR" for i in range(1, 100_001))
+    result = run(parse_grep("ERROR"), text)
+    assert result.matched == 100
+    assert not result.partial
+
+
+def test_to_command() -> None:
+    assert to_command(parse_grep("-i -C 2 -E 'conn(ect)?'")) == "grep -iE -C 2 'conn(ect)?'"
+    assert to_command(GrepQuery("-x")) == "grep -- -x"
+    assert parse_grep(to_command(parse_grep("-vc 'a b'"))) == parse_grep("-vc 'a b'")
+
+
+def test_catastrophic_lines_are_skipped_then_budget_stops() -> None:
+    text = "\n".join(["a" * 40 + "!"] * 100)
+    result = run(parse_grep("-E '(a|aa)+$'"), text, budget=0.3)
+    assert result.skipped >= 1
+    assert result.partial
diff --git a/tests/runtime/fake_docker.py b/tests/runtime/fake_docker.py
index bd5f9ed..5112a8f 100644
--- a/tests/runtime/fake_docker.py
+++ b/tests/runtime/fake_docker.py
@@ -97,7 +97,8 @@ class FakeDocker:
                     return httpx.Response(200, json=self._stats(c))
                 case "logs":
                     since = datetime.fromtimestamp(int(q.get("since", "0")), UTC)
-                    body = b"".join(frame(line + "\n", 2 if "ERR" in line else 1) for at, line in c.logs if at >= since)
+                    picked = [line for at, line in c.logs if at >= since][-int(q.get("tail", "1000000")) :]
+                    body = b"".join(frame(line + "\n", 2 if "ERR" in line else 1) for line in picked)
                     return httpx.Response(200, content=body)
         return httpx.Response(404, json={"message": "No such container"})