Unrendered ANSI codes

[ShiftPoster]

Running into an issue where I have logs coming from another thread while the prompt is waiting for user input. Instead of nicely colored text, the ANSI escape codes are shown. Is there a way to avoid this?

Thank you.

I am running this on Windows 10 with the following:

>python --version
Python 3.12.2

>pip show cmd2
Name: cmd2
Version: 4.2.4

This can replicate the problem:

import logging
from collections.abc import Generator
from contextlib import contextmanager
from dataclasses import dataclass, field
from pathlib import Path
from threading import Event, Thread

from cmd2 import Cmd
from rich.logging import RichHandler

FORMAT = "%(message)s"
logging.basicConfig(
    level="NOTSET", format=FORMAT, datefmt="[%X]", handlers=[RichHandler()]
)
logging.getLogger("asyncio").setLevel(logging.ERROR)
logger =  logging.getLogger(Path(__file__).with_suffix("").name)


@dataclass
class Worker:
    stop: Event = field(default_factory=Event)

    def run(self):
        while not self.stop.is_set():
            logger.info("Something happened!")
            self.stop.wait(.5)

    @contextmanager
    def run_in_thread(self) -> Generator[None, None, None]:
        thread = Thread(target=self.run)
        thread.start()
        try:
            yield
        finally:
            self.stop.set()
            thread.join()


logger.info("Running!")
with Worker().run_in_thread():
    Cmd(allow_cli_args=False).cmdloop()
logger.info("Done!")

[jdfesa]

Yes — route the background log messages through Cmd.add_alert() instead of writing directly through RichHandler while the prompt is active.

In cmd2 4.2.4, interactive input runs inside prompt_toolkit.patch_stdout() with its default raw=False. That path escapes terminal control sequences, which explains why Rich's ANSI output is visible as text. cmd2's alert path renders the message and prints it through an ANSI-aware prompt-toolkit call.

For your example, replace the logging setup with a small handler:

from rich.text import Text

class PromptLogHandler(logging.Handler):
    def __init__(self, app):
        super().__init__()
        self.app = app

    def emit(self, record):
        try:
            self.app.add_alert(
                msg=Text(self.format(record), style="cyan")
            )
        except Exception:
            self.handleError(record)

app = Cmd(allow_cli_args=False)
logging.basicConfig(
    level=logging.INFO,
    format="%(message)s",
    handlers=[PromptLogHandler(app)],
    force=True,
)

with Worker().run_in_thread():
    app.cmdloop()

Keep your Worker implementation unchanged. This intentionally replaces RichHandler's formatting; you can choose the Text style by log level if needed. Remove the old RichHandler rather than leaving both handlers attached.

add_alert() accepts Rich renderables, and the project's async printing example uses it from a worker thread. Alerts are queued for display when the prompt is active, so this is not an immediate-output handler for logs before or after cmdloop().

[ShiftPoster]

Thank you for the quick response! This set me on the right path. Unfortunately, the alerts are also not an output handler during commands either. This can be seen when putting a sleep in a command and running the command, all logs are paused until the command finishes and we return to the prompt.

This is a bit of an issue for me, but it can be worked around by using an event to signal the prompt is active/inactive like below, but I was wondering if there was a built in event to wait for?

class MyCmd(Cmd):
    _prompt_active: Event

    @property
    def prompt_active(self) -> bool:
        return self._prompt_active.is_set()

    def __init__(self, *args, **kwargs):
        self._prompt_active = Event()
        super().__init__(*args, **kwargs)
        self.register_precmd_hook(self._hook_prompt_clear)

    def pre_prompt(self) -> None:
        # Signal the prompt has started
        self._prompt_active.set()

    def _hook_prompt_clear(self, data: PrecommandData) -> PrecommandData:
        # Signal exit from the prompt, hopefully this is as close as we can get
        self._prompt_active.clear()
        return data

    def do_hello(self, _):
        logger.warning("Hello world!")
        time.sleep(2)
        logger.warning("Hello world!")


class CmdHandler(logging.StreamHandler):
    app: MyCmd | None = None

    def emit(self, record: logging.LogRecord) -> None:
        try:
            if self.app and self.app.prompt_active:
                self.app.add_alert(msg=Text(self.format(record), style="cyan"))
            else:
                super().emit(record)
        except Exception:
            self.handleError(record)


# Stream handler for emitting while outside of Cmd application
console_handler: CmdHandler = CmdHandler(sys.stdout)
logging.basicConfig(
    level="NOTSET", format="%(message)s", datefmt="[%X]", handlers=[console_handler]
)
logging.getLogger("asyncio").setLevel(logging.ERROR)

logger.info("Running!")
# In practice, I initialize logging before anything else
cmd = MyCmd(allow_cli_args=False)
with Worker().run_in_thread():
    # Setting and clearing the app attribute can be done with a context manager
    console_handler.app = cmd
    cmd.cmdloop()
    console_handler.app = None
logger.info("Done!")

In the image, the cyan text is from the logs emitted to the alert, and white are normal logs to stdout.

[ShiftPoster]

My final solution below. Thank you @jdfesa for the app.add_alert, it works great for my situation. Also thanks @Erfouni , I like having options, especially when they require less typing. I'll whip that one out when I'm not using Progress.

class MyCmd(Cmd):

    # Unchanged

    def do_hello(self, _):
        with Progress() as progress:
            progress.add_task("[cyan]Working...", total=None)
            logger.warning("Hello world!")
            time.sleep(2)
            logger.warning("Hello world!")


class CmdHandler(RichHandler):
    app: MyCmd | None = None

    def _get_renderable(self, record: logging.LogRecord) -> ConsoleRenderable:
        """Copied from `RichHandler.emit` for formatting."""
        message = self.format(record)
        traceback = None
        if (
            self.rich_tracebacks
            and record.exc_info
            and record.exc_info != (None, None, None)
        ):
            exc_type, exc_value, exc_traceback = record.exc_info
            assert exc_type is not None
            assert exc_value is not None
            from rich.traceback import Traceback

            traceback = Traceback.from_exception(
                exc_type,
                exc_value,
                exc_traceback,
                width=self.tracebacks_width,
                code_width=self.tracebacks_code_width,
                extra_lines=self.tracebacks_extra_lines,
                theme=self.tracebacks_theme,
                word_wrap=self.tracebacks_word_wrap,
                show_locals=self.tracebacks_show_locals,
                locals_max_length=self.locals_max_length,
                locals_max_string=self.locals_max_string,
                suppress=self.tracebacks_suppress,
                max_frames=self.tracebacks_max_frames,
            )
            message = record.getMessage()
            if self.formatter:
                record.message = record.getMessage()
                formatter = self.formatter
                if hasattr(formatter, "usesTime") and formatter.usesTime():
                    record.asctime = formatter.formatTime(record, formatter.datefmt)
                message = formatter.formatMessage(record)

        message_renderable = self.render_message(record, message)
        return self.render(
            record=record, traceback=traceback, message_renderable=message_renderable
        )

    def emit(self, record: logging.LogRecord) -> None:
        """Unchanged."""


console_handler: CmdHandler = CmdHandler(omit_repeated_times=False)
logging.basicConfig(
    level="NOTSET", format="%(message)s", datefmt="[%X]", handlers=[console_handler]
)
logging.getLogger("asyncio").setLevel(logging.ERROR)
logger =  logging.getLogger(Path(__file__).with_suffix("").name)


@contextmanager
def cmd_handler(app: MyCmd):
    backup = console_handler.enable_link_path
    console_handler.enable_link_path = False
    console_handler.app = app
    try:
        yield
    finally:
        console_handler.enable_link_path = backup
        console_handler.app = None


logger.info("Running!")
cmd = MyCmd(allow_cli_args=False)
with Worker().run_in_thread(), cmd_handler(cmd):
    cmd.cmdloop()
logger.info("Done!")

[Erfouni]

No public event for that in 4.2.4. cmd2 keeps it in a private flag (_alert_allowed, set in _pre_prompt and cleared when the prompt returns), so your Event is about as good as it gets from outside.

You don't need it though. prompt_toolkit's print_formatted_text already checks whether a prompt is running: if one is, it prints above it (thread-safe, through run_in_terminal), otherwise it writes straight to the terminal. Wrap the text in ANSI() and Rich's colors survive, so you can keep RichHandler and give it a console that writes through that:

import io
import logging

from prompt_toolkit import print_formatted_text
from prompt_toolkit.formatted_text import ANSI
from rich.console import Console
from rich.logging import RichHandler


class PromptToolkitWriter(io.TextIOBase):
    def write(self, s):
        if s:
            print_formatted_text(ANSI(s), end="")
        return len(s)


console = Console(file=PromptToolkitWriter(), force_terminal=True)
logging.basicConfig(
    level="NOTSET",
    format="%(message)s",
    datefmt="[%X]",
    handlers=[RichHandler(console=console, enable_link_path=False)],
)

That one handler covers the prompt, a running command, and before/after cmdloop(), so add_alert and the hooks aren't needed. Keep enable_link_path=False: prompt_toolkit's ANSI parser only understands color codes, and Rich's clickable file links would print as 8;id=...;file://... junk.

The ?[ text comes from cmd2 reading input inside patch_stdout() with raw=False, which escapes ESC for anything printed while the prompt is up.

Tried with your script plus a command that sleeps 1.5 s (Windows 11, Python 3.13, cmd2 4.2.4, prompt_toolkit 3.0.53, rich 15.0.0): colors are right at the prompt, during the command and after it. Not tried on Python 3.12 or the classic Windows 10 console.

[ShiftPoster]

This works great! The only problem I run into is when used with rich.progress.Progress.

Source:

# Changed from io.TextIOBase to avoid type error
class PromptToolkitWriter(io.StringIO):
    def write(self, s):
        if s:
            print_formatted_text(ANSI(s), end="")
        return len(s)


console = Console(file=PromptToolkitWriter(), force_terminal=True)
logging.basicConfig(
    level="NOTSET",
    format="%(message)s",
    datefmt="[%X]",
    handlers=[RichHandler(console=console, enable_link_path=False)],
)
logger =  logging.getLogger(__name__)


class MyCmd(Cmd):
    def do_hello(self, _):
        with Progress() as progress:
            progress.add_task("[cyan]Working...", total=None)
            logger.warning("Hello world!")
            time.sleep(2)
            logger.warning("Hello world!")


logger.info("Running!")
cmd = MyCmd(allow_cli_args=False)
with Worker().run_in_thread():
    cmd.cmdloop()
logger.info("Done!")

[tleonhardt]

@ShiftPoster @jdfesa @Erfouni I love to see users helping each other out like this. Great work and suggestions all!

If anyone has ideas for how to make things better in cmd2 and/or better in the documentation, please don't hesitate to create an Issue or submit a PR.