feat(logs): раздел «Логи» — хвост и свой grep (#16)

- 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 <noreply@anthropic.com>

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])

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))
 

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), "<b>html-ish</b> & 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 "&lt;b&gt;html-ish&lt;/b&gt; &amp; 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 "<code>grep -i -C 1 error</code>" 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 "<pre>" 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]

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

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"})