diff --git a/codex_telegram_bridge/src/codex_telegram_bridge/exec_bridge.py b/codex_telegram_bridge/src/codex_telegram_bridge/exec_bridge.py index e505464..c110120 100644 --- a/codex_telegram_bridge/src/codex_telegram_bridge/exec_bridge.py +++ b/codex_telegram_bridge/src/codex_telegram_bridge/exec_bridge.py @@ -53,7 +53,7 @@ async def _drain_stderr(stderr: asyncio.StreamReader | None, tail: deque[str]) - logger.debug("[codex][stderr] drain error: %s", e) -def setup_logging(log_file: str | None) -> None: +def setup_logging(log_file: str | None, *, debug: bool = False) -> None: root_logger = logging.getLogger() root_logger.setLevel(logging.DEBUG) for handler in root_logger.handlers[:]: @@ -63,7 +63,7 @@ def setup_logging(log_file: str | None) -> None: fmt = logging.Formatter("%(asctime)s %(levelname)s %(name)s: %(message)s") console = logging.StreamHandler(sys.stdout) - console.setLevel(logging.INFO) + console.setLevel(logging.DEBUG if debug else logging.INFO) console.setFormatter(fmt) root_logger.addHandler(console) @@ -74,7 +74,7 @@ def setup_logging(log_file: str | None) -> None: backupCount=3, encoding="utf-8", ) - file_handler.setLevel(logging.DEBUG) + file_handler.setLevel(logging.DEBUG if debug else logging.INFO) file_handler.setFormatter(fmt) root_logger.addHandler(file_handler) logger.debug("[debug] file logger initialized path=%r", log_file) @@ -169,7 +169,10 @@ class CodexExecRunner: """ def __init__( - self, codex_cmd: str, workspace: str | None, extra_args: list[str] + self, + codex_cmd: str, + workspace: str | None, + extra_args: list[str], ) -> None: self.codex_cmd = codex_cmd self.workspace = workspace @@ -196,6 +199,7 @@ class CodexExecRunner: logger.info( "[codex] start run session_id=%r workspace=%r", session_id, self.workspace ) + logger.debug("[codex] prompt: %s", prompt) args = [self.codex_cmd, "exec", "--json"] args.extend(self.extra_args) if self.workspace: @@ -233,12 +237,15 @@ class CodexExecRunner: proc.stdin.close() async for raw_line in proc.stdout: - line = raw_line.decode(errors="replace").strip() + raw = raw_line.decode(errors="replace") + logger.debug("[codex][jsonl] %s", raw.rstrip("\n")) + line = raw.strip() if not line: continue try: evt = json.loads(line) except json.JSONDecodeError: + logger.debug("[codex][jsonl] invalid line: %r", line) continue cli_last_turn, out_lines = render_event_cli(evt, cli_last_turn) @@ -400,6 +407,7 @@ def _parse_bridge_config( async def _send_startup(cfg: BridgeConfig) -> None: try: + logger.debug("[startup] message: %s", cfg.startup_msg) await cfg.bot.send_message(chat_id=cfg.chat_id, text=cfg.startup_msg) logger.info("[startup] sent startup message to chat_id=%s", cfg.chat_id) except Exception as e: @@ -418,6 +426,7 @@ async def _drain_backlog(cfg: BridgeConfig, offset: int | None) -> int | None: except Exception as e: logger.info("[startup] backlog drain failed: %s", e) return offset + logger.debug("[startup] backlog updates: %s", updates) if updates: offset = updates[-1]["update_id"] + 1 logger.info("[startup] drained %s pending update(s)", len(updates)) @@ -433,6 +442,13 @@ async def _handle_message( text: str, resume_session: str | None, ) -> None: + logger.debug( + "[handle] incoming chat_id=%s message_id=%s resume=%r text=%s", + chat_id, + user_msg_id, + resume_session, + text, + ) started_at = time.monotonic() progress_renderer = ExecProgressRenderer(max_actions=5) @@ -445,6 +461,13 @@ async def _handle_message( if progress_id is None: return rendered, entities = render_for_telegram(md, limit=TELEGRAM_TEXT_LIMIT) + logger.debug( + "[progress] edit message_id=%s md=%s rendered=%s entities=%s", + progress_id, + md, + rendered, + entities, + ) try: await cfg.bot.edit_message_text( chat_id=chat_id, @@ -465,6 +488,13 @@ async def _handle_message( initial_rendered, initial_entities = render_for_telegram( initial_md, limit=TELEGRAM_TEXT_LIMIT ) + logger.debug( + "[progress] send reply_to=%s md=%s rendered=%s entities=%s", + user_msg_id, + initial_md, + initial_rendered, + initial_entities, + ) progress_msg = await cfg.bot.send_message( chat_id=chat_id, text=initial_rendered, @@ -509,12 +539,18 @@ async def _handle_message( err = _clamp_tg_text(f"Error:\n{e}") if progress_id is not None and len(err) <= TELEGRAM_TEXT_LIMIT: try: + logger.debug( + "[error] edit message_id=%s text=%s", progress_id, err + ) await cfg.bot.edit_message_text( chat_id=chat_id, message_id=progress_id, text=err ) return except Exception: pass + logger.debug( + "[error] send reply_to=%s text=%s", user_msg_id, err + ) await _send_markdown( cfg.bot, chat_id=chat_id, @@ -534,10 +570,17 @@ async def _handle_message( progress_renderer.render_final(elapsed, answer, status=status) + f"\n\nresume: `{session_id}`" ) + logger.debug("[final] markdown: %s", final_md) final_rendered, final_entities = render_markdown(final_md) can_edit_final = progress_id is not None and len(final_rendered) <= TELEGRAM_TEXT_LIMIT if cfg.final_notify or not can_edit_final: + logger.debug( + "[final] send reply_to=%s rendered=%s entities=%s", + user_msg_id, + final_rendered, + final_entities, + ) await _send_markdown( cfg.bot, chat_id=chat_id, @@ -547,10 +590,17 @@ async def _handle_message( ) if progress_id is not None: try: + logger.debug("[final] delete progress message_id=%s", progress_id) await cfg.bot.delete_message(chat_id=chat_id, message_id=progress_id) except Exception: pass else: + logger.debug( + "[final] edit message_id=%s rendered=%s entities=%s", + progress_id, + final_rendered, + final_entities, + ) await cfg.bot.edit_message_text( chat_id=chat_id, message_id=progress_id, @@ -587,6 +637,7 @@ async def _run_main_loop(cfg: BridgeConfig) -> None: logger.info("[loop] getUpdates failed: %s", e) await asyncio.sleep(2) continue + logger.debug("[loop] updates: %s", updates) for upd in updates: offset = upd["update_id"] + 1 @@ -646,6 +697,11 @@ def run( "--ignore-backlog/--process-backlog", help="Skip pending Telegram updates that arrived before startup.", ), + debug: bool = typer.Option( + False, + "--debug/--no-debug", + help="Log codex JSONL, Telegram requests, and rendered messages.", + ), log_file: str | None = typer.Option( "exec_bridge.log", "--log-file", @@ -662,7 +718,7 @@ def run( help="Codex model to pass to `codex exec`.", ), ) -> None: - setup_logging(log_file if log_file else None) + setup_logging(log_file if log_file else None, debug=debug) cfg = _parse_bridge_config( progress_edit_every_s=progress_edit_every_s, progress_silent=progress_silent, diff --git a/codex_telegram_bridge/src/codex_telegram_bridge/exec_render.py b/codex_telegram_bridge/src/codex_telegram_bridge/exec_render.py index eb12999..ae8c595 100644 --- a/codex_telegram_bridge/src/codex_telegram_bridge/exec_render.py +++ b/codex_telegram_bridge/src/codex_telegram_bridge/exec_render.py @@ -11,7 +11,7 @@ STATUS_DONE = "✓" HEADER_SEP = " · " HARD_BREAK = " \n" -MAX_CMD_LEN = 40 +MAX_PROGRESS_CMD_LEN = 300 MAX_QUERY_LEN = 60 MAX_PATH_LEN = 40 MAX_PROGRESS_CHARS = 300 @@ -64,6 +64,8 @@ def _shorten_path(path: str, width: int) -> str: def format_event( event: dict[str, Any], last_item: int | None, + *, + command_width: int | None = None, ) -> tuple[int | None, list[str], str | None, str | None]: """ Returns (new_last_item, cli_lines, progress_line, progress_prefix). @@ -95,14 +97,22 @@ def format_event( lines.extend(indent(item["text"], " ").splitlines()) return last_item, lines, None, None case ("reasoning", "item.completed"): - line = prefix + item["text"] + text = item.get("text") or "" + first_line = text.splitlines()[0] if text else "" + line = prefix + first_line return last_item, [line], line, prefix case ("command_execution", "item.started"): - command = f"`{_shorten(item['command'], MAX_CMD_LEN)}`" + command = item["command"] + if command_width is not None: + command = _shorten(command, command_width) + command = f"`{command}`" line = prefix + f"{STATUS_RUNNING} running: {command}" return last_item, [line], line, prefix case ("command_execution", "item.completed"): - command = f"`{_shorten(item['command'], MAX_CMD_LEN)}`" + command = item["command"] + if command_width is not None: + command = _shorten(command, command_width) + command = f"`{command}`" exit_code = item["exit_code"] exit_part = f" (exit {exit_code})" if exit_code is not None else "" line = prefix + f"{STATUS_DONE} ran: {command}{exit_part}" @@ -143,14 +153,20 @@ def format_event( def render_event_cli( event: dict[str, Any], last_item: int | None = None ) -> tuple[int | None, list[str]]: - last_item, cli_lines, _, _ = format_event(event, last_item) + last_item, cli_lines, _, _ = format_event(event, last_item, command_width=None) return last_item, cli_lines class ExecProgressRenderer: - def __init__(self, max_actions: int = 5, max_chars: int = MAX_PROGRESS_CHARS) -> None: + def __init__( + self, + max_actions: int = 5, + max_chars: int = MAX_PROGRESS_CHARS, + command_width: int | None = MAX_PROGRESS_CMD_LEN, + ) -> None: self.max_actions = max_actions self.max_chars = max_chars + self.command_width = command_width self.recent_actions: deque[str] = deque(maxlen=max_actions) self.turn_count: int | None = None self.last_item: int | None = None @@ -162,7 +178,9 @@ class ExecProgressRenderer: self.turn_count = 1 if self.turn_count is None else self.turn_count + 1 return True - self.last_item, _, progress_line, progress_prefix = format_event(event, self.last_item) + self.last_item, _, progress_line, progress_prefix = format_event( + event, self.last_item, command_width=self.command_width + ) if progress_line is None: return False diff --git a/codex_telegram_bridge/src/codex_telegram_bridge/telegram_client.py b/codex_telegram_bridge/src/codex_telegram_bridge/telegram_client.py index cacbed7..0f04ca2 100644 --- a/codex_telegram_bridge/src/codex_telegram_bridge/telegram_client.py +++ b/codex_telegram_bridge/src/codex_telegram_bridge/telegram_client.py @@ -24,11 +24,13 @@ class TelegramClient: async def _post(self, method: str, json_data: dict[str, Any]) -> Any: try: + logger.debug("[telegram] request %s: %s", method, json_data) resp = await self._client.post(f"{self._base}/{method}", json=json_data) resp.raise_for_status() payload = resp.json() if not payload.get("ok"): raise RuntimeError(f"Telegram API error: {payload}") + logger.debug("[telegram] response %s: %s", method, payload) return payload["result"] except httpx.HTTPError as e: logger.error("Telegram network error: %s", e)