141 lines
5.0 KiB
Python
141 lines
5.0 KiB
Python
"""Serial byte stream -> framed, cleaned, parsed log lines.
|
|
|
|
ESP-IDF log format: "<L> (<ms since boot>) <TAG>: <message>", optionally
|
|
wrapped in ANSI colour codes. ROM/bootloader output (boot banner, reset
|
|
reason) has no level prefix and is classified separately, since a boot
|
|
banner is the only reliable reboot marker.
|
|
"""
|
|
|
|
from __future__ import annotations
|
|
|
|
import re
|
|
import time
|
|
from dataclasses import dataclass, field
|
|
from enum import Enum
|
|
|
|
from .redact import redact
|
|
|
|
ANSI_RE = re.compile(r"\x1b\[[0-9;]*[A-Za-z]")
|
|
ESP_LOG_RE = re.compile(r"^([EWIDV]) \((\d+)\) ([^:]{1,40}?): ?(.*)$")
|
|
# ESP32-S3 ROM prints e.g. "ESP-ROM:esp32s3-20210327" then
|
|
# "rst:0x1 (POWERON),boot:0x8 (SPI_FAST_FLASH_BOOT)".
|
|
BOOT_BANNER_RE = re.compile(r"^ESP-ROM:")
|
|
RESET_REASON_RE = re.compile(r"^rst:0x([0-9a-fA-F]+) \(([A-Z0-9_]+)\)")
|
|
PANIC_RE = re.compile(
|
|
r"Guru Meditation Error|abort\(\) was called|ESP_ERROR_CHECK failed|"
|
|
r"^Backtrace:|Rebooting\.\.\.$"
|
|
)
|
|
|
|
|
|
class LineKind(str, Enum):
|
|
LOG = "log" # ESP_LOGx line
|
|
BOOT = "boot" # ROM boot banner (start of a new boot)
|
|
RESET = "reset" # ROM reset-reason line
|
|
PANIC = "panic" # crash / abort output
|
|
RAW = "raw" # anything else (task list rows, line protocol, ...)
|
|
HOST = "host" # event generated by this tool (connect, reset, ...)
|
|
|
|
|
|
def host_event(text: str) -> LogLine:
|
|
return LogLine(f"--- {text} ---", LineKind.HOST)
|
|
|
|
|
|
@dataclass(frozen=True)
|
|
class LogLine:
|
|
text: str # cleaned + redacted
|
|
kind: LineKind
|
|
host_time: float = field(default_factory=time.time)
|
|
level: str | None = None # E/W/I/D/V for LOG lines
|
|
uptime_ms: int | None = None
|
|
tag: str | None = None
|
|
message: str | None = None
|
|
reset_reason: str | None = None
|
|
|
|
|
|
def clean(raw: str) -> str:
|
|
return ANSI_RE.sub("", raw).replace("\r", "").rstrip()
|
|
|
|
|
|
def parse_line(raw: str, host_time: float | None = None) -> LogLine:
|
|
text = redact(clean(raw))
|
|
t = time.time() if host_time is None else host_time
|
|
if m := ESP_LOG_RE.match(text):
|
|
level, ms, tag, msg = m.groups()
|
|
return LogLine(text, LineKind.LOG, t, level, int(ms), tag.strip(), msg)
|
|
if BOOT_BANNER_RE.match(text):
|
|
return LogLine(text, LineKind.BOOT, t)
|
|
if m := RESET_REASON_RE.match(text):
|
|
return LogLine(text, LineKind.RESET, t, reset_reason=m.group(2))
|
|
if PANIC_RE.search(text):
|
|
return LogLine(text, LineKind.PANIC, t)
|
|
return LogLine(text, LineKind.RAW, t)
|
|
|
|
|
|
class LineFramer:
|
|
"""Accumulates bytes and yields complete lines.
|
|
|
|
A partial line is released after `idle_flush_s` without new bytes so
|
|
prompts / unterminated output are not held back forever.
|
|
"""
|
|
|
|
# Stale FIFO bytes arrive immediately after open; anything later is live.
|
|
STALE_WINDOW_S = 0.25
|
|
|
|
def __init__(self, idle_flush_s: float = 0.3, max_line: int = 4096,
|
|
drop_first_partial: bool = False, now: float | None = None):
|
|
self._buf = bytearray()
|
|
self._last_rx = 0.0
|
|
self.idle_flush_s = idle_flush_s
|
|
self.max_line = max_line
|
|
# The S3 USB-Serial-JTAG FIFO keeps the tail of an old line while no
|
|
# host is reading and flushes it on open; drop bytes up to the first
|
|
# newline after a (re)connect so it is not glued to a fresh line.
|
|
# Only bytes arriving within STALE_WINDOW_S of open are considered
|
|
# stale, otherwise an idle board's next boot banner would be lost.
|
|
self._dropping = drop_first_partial
|
|
self._drop_deadline = (time.monotonic() if now is None else now) + self.STALE_WINDOW_S
|
|
|
|
def cancel_drop(self) -> None:
|
|
self._dropping = False
|
|
|
|
def feed(self, data: bytes, now: float | None = None) -> list[str]:
|
|
now = time.monotonic() if now is None else now
|
|
if self._dropping and now > self._drop_deadline:
|
|
self._dropping = False
|
|
if data:
|
|
self._buf.extend(data)
|
|
self._last_rx = now
|
|
if self._dropping:
|
|
i = self._buf.find(b"\n")
|
|
if i < 0:
|
|
return []
|
|
del self._buf[: i + 1]
|
|
self._dropping = False
|
|
out: list[str] = []
|
|
while (i := self._buf.find(b"\n")) >= 0:
|
|
out.append(self._decode(self._buf[:i]))
|
|
del self._buf[: i + 1]
|
|
if len(self._buf) >= self.max_line:
|
|
out.append(self._decode(self._buf))
|
|
self._buf.clear()
|
|
return out
|
|
|
|
def poll_idle(self, now: float | None = None) -> list[str]:
|
|
now = time.monotonic() if now is None else now
|
|
if self._buf and now - self._last_rx >= self.idle_flush_s:
|
|
line = self._decode(self._buf)
|
|
self._buf.clear()
|
|
return [line]
|
|
return []
|
|
|
|
def flush(self) -> list[str]:
|
|
if not self._buf:
|
|
return []
|
|
line = self._decode(self._buf)
|
|
self._buf.clear()
|
|
return [line]
|
|
|
|
@staticmethod
|
|
def _decode(b: bytes | bytearray) -> str:
|
|
return bytes(b).decode("utf-8", errors="replace")
|