diff --git a/codeplain_REST_api.py b/codeplain_REST_api.py index 33542d2e..341fcc17 100644 --- a/codeplain_REST_api.py +++ b/codeplain_REST_api.py @@ -5,6 +5,7 @@ from requests.exceptions import ConnectionError, RequestException, Timeout import plain2code_exceptions +from plain2code_console import RETRY_COLOR from plain2code_state import RunState MAX_RETRIES = 4 @@ -67,8 +68,11 @@ def _handle_retry_logic( connection_error_type = "Network error" if is_connection_error else "Error" if attempt < num_retries: if not silent: - self.console.debug(f"{connection_error_type} on attempt {attempt + 1}/{num_retries + 1}: {error}") - self.console.debug(f"Retrying in {retry_delay} seconds...") + self.console.debug( + f"↻ {connection_error_type} on attempt {attempt + 1}/{num_retries + 1}: {error}. " + f"Retrying in {retry_delay} seconds...", + color=RETRY_COLOR, + ) time.sleep(retry_delay) # Exponential backoff return retry_delay * 2 diff --git a/plain2code_console.py b/plain2code_console.py index c534f147..e5047ac7 100644 --- a/plain2code_console.py +++ b/plain2code_console.py @@ -11,6 +11,12 @@ logger = logging.getLogger(plain2code_logger.LOGGER_NAME) +# Colors for log messages, applied by the terminal and the TUI via the "color" +# parameter of the console methods. The file log always receives plain text. +RETRY_COLOR = "#FFB454" # Amber +SUCCESS_COLOR = "#79FC96" # Green +MUTED_COLOR = "#888888" # Grey + class Plain2CodeConsole(Console): INFO_STYLE = Style() @@ -33,30 +39,37 @@ def __init__(self): logger.debug(f"Exception: {e}") self.llm_encoding = None - def info(self, *args, **kwargs): - logger.info(" ".join(map(str, args))) - super().print(*args, **kwargs, style=self.INFO_STYLE) + def info(self, *args, color=None, **kwargs): + self._log_and_print(logging.INFO, self.INFO_STYLE, args, color, kwargs) - def warning(self, *args, **kwargs): - logger.warning(" ".join(map(str, args))) - super().print(*args, **kwargs, style=self.WARNING_STYLE) + def warning(self, *args, color=None, **kwargs): + self._log_and_print(logging.WARNING, self.WARNING_STYLE, args, color, kwargs) - def error(self, *args, **kwargs): - logger.error(" ".join(map(str, args))) - super().print(*args, **kwargs, style=self.ERROR_STYLE) + def error(self, *args, color=None, **kwargs): + self._log_and_print(logging.ERROR, self.ERROR_STYLE, args, color, kwargs) - def input(self, *args, **kwargs): + def input(self, *args, color=None, **kwargs): # We also log input as info so it shows in the toggled view - logger.info(" ".join(map(str, args))) - super().print(*args, **kwargs, style=self.INPUT_STYLE) + self._log_and_print(logging.INFO, self.INPUT_STYLE, args, color, kwargs) + + def output(self, *args, color=None, **kwargs): + self._log_and_print(logging.INFO, self.OUTPUT_STYLE, args, color, kwargs) - def output(self, *args, **kwargs): - logger.info(" ".join(map(str, args))) - super().print(*args, **kwargs, style=self.OUTPUT_STYLE) + def debug(self, *args, color=None, **kwargs): + self._log_and_print(logging.DEBUG, self.DEBUG_STYLE, args, color, kwargs) - def debug(self, *args, **kwargs): - logger.debug(" ".join(map(str, args))) - super().print(*args, **kwargs, style=self.DEBUG_STYLE) + def _log_and_print(self, level, base_style, args, color, kwargs): + """Log the plain message text, then print it styled to the terminal. + + The optional color is applied by the terminal (via style) and forwarded to + the TUI as the "log_color" record attribute; the file log stays plain text. + """ + logger.log(level, " ".join(map(str, args)), extra={"log_color": color}) + style = base_style + Style(color=color) if color else base_style + # Log messages must render exactly as logged: don't interpret square brackets + # in interpolated content (error texts, file names) as Rich markup. + kwargs.setdefault("markup", False) + super().print(*args, **kwargs, style=style) def print_list(self, items, style=None): for item in items: @@ -130,9 +143,7 @@ def print_resources(self, resources_list, linked_resources): for resource_name in resources_list: if resource_name["target"] in linked_resources: file_tokens = self._count_tokens(linked_resources[resource_name["target"]]) - self.debug( - f"- {resource_name['text']} [#4169E1]({resource_name['target']}, {file_tokens} tokens)[/#4169E1]" - ) + self.debug(f"- {resource_name['text']} ({resource_name['target']}, {file_tokens} tokens)") self.input() diff --git a/plain2code_events.py b/plain2code_events.py index befea2c4..f9fb40b4 100644 --- a/plain2code_events.py +++ b/plain2code_events.py @@ -44,6 +44,7 @@ class LogMessageEmitted(BaseEvent): level: str # e.g., "INFO", "DEBUG", "ERROR" message: str # The actual log message timestamp: str # Formatted timestamp + log_color: Optional[str] = None # Color for the message (e.g. "#FFB454"); the file log stays plain text @dataclass diff --git a/plain2code_logger.py b/plain2code_logger.py index 12f863b8..f0bf7691 100644 --- a/plain2code_logger.py +++ b/plain2code_logger.py @@ -88,6 +88,7 @@ def emit(self, record): level=record.levelname, message=record.getMessage(), timestamp=timestamp, + log_color=getattr(record, "log_color", None), ) self.event_bus.publish(event) except RuntimeError: diff --git a/render_machine/actions/create_dist.py b/render_machine/actions/create_dist.py index ef78fb9f..9a1dfd4d 100644 --- a/render_machine/actions/create_dist.py +++ b/render_machine/actions/create_dist.py @@ -1,7 +1,7 @@ from typing import Any import file_utils -from plain2code_console import console +from plain2code_console import SUCCESS_COLOR, console from render_machine.actions.base_action import BaseAction from render_machine.render_context import RenderContext @@ -21,6 +21,6 @@ def execute(self, render_context: RenderContext, _previous_action_payload: Any | render_context.conformance_tests.get_module_conformance_tests_folder(render_context.module_name), render_context.conformance_tests_dest, ) - console.info(f"[#79FC96]Render of module {render_context.module_name} completed successfully.[/#79FC96]") + console.info(f"✓ Render of module {render_context.module_name} completed successfully.", color=SUCCESS_COLOR) return self.SUCCESSFUL_OUTCOME, None diff --git a/render_machine/actions/exit_with_error.py b/render_machine/actions/exit_with_error.py index d6698621..d49b956b 100644 --- a/render_machine/actions/exit_with_error.py +++ b/render_machine/actions/exit_with_error.py @@ -20,7 +20,8 @@ def execute(self, render_context: RenderContext, previous_action_payload: Any | if render_context.frid_context is not None: console.info( - f"To continue rendering from the last successfully rendered functionality, provide the [red]--render-from {render_context.frid_context.frid}[/red] flag." + f"To continue rendering from the last successfully rendered functionality, " + f"provide the --render-from {render_context.frid_context.frid} flag." ) if render_context.run_state.render_id is not None: diff --git a/render_machine/actions/fix_conformance_test.py b/render_machine/actions/fix_conformance_test.py index dad9337d..5d68cc88 100644 --- a/render_machine/actions/fix_conformance_test.py +++ b/render_machine/actions/fix_conformance_test.py @@ -4,7 +4,7 @@ import file_utils import plain_spec from memory_management import MemoryManager -from plain2code_console import console +from plain2code_console import RETRY_COLOR, console from plain2code_exceptions import InternalClientError from render_machine.actions.base_action import BaseAction from render_machine.implementation_code_helpers import ImplementationCodeHelpers @@ -144,7 +144,9 @@ def execute(self, render_context: RenderContext, previous_action_payload: Any | render_context.conformance_tests_running_context.conflicting_module_name = current_testing_module_name render_context.conformance_tests_running_context.conflicting_frid = current_testing_frid console.info( - f"Potential conflicting functionalities detected while fixing conformance tests for functionality {current_testing_frid} in module {current_testing_module_name}." + f"↻ Potential conflicting functionalities detected while fixing conformance tests " + f"for functionality {current_testing_frid} in module {current_testing_module_name}.", + color=RETRY_COLOR, ) if issue_reason_code == self.ISSUE_REASON_CODE_CONFORMANCE_TESTS: diff --git a/render_machine/actions/render_functional_requirement.py b/render_machine/actions/render_functional_requirement.py index ea20ad36..07fa924e 100644 --- a/render_machine/actions/render_functional_requirement.py +++ b/render_machine/actions/render_functional_requirement.py @@ -3,7 +3,7 @@ import file_utils import render_machine.render_utils as render_utils from memory_management import MemoryManager -from plain2code_console import console +from plain2code_console import RETRY_COLOR, console from plain2code_exceptions import FunctionalRequirementTooComplex from render_machine.actions.base_action import BaseAction from render_machine.implementation_code_helpers import ImplementationCodeHelpers @@ -28,8 +28,9 @@ def execute(self, render_context: RenderContext, _previous_action_payload: Any | if render_context.frid_context.functional_requirement_render_attempts > 1: console.info( - f"Unittests could not be fixed after rendering the functionality. " - f"Restarting rendering functionality {render_context.frid_context.frid} from scratch." + f"↻ Unittests could not be fixed after rendering the functionality. " + f"Restarting rendering functionality {render_context.frid_context.frid} from scratch.", + color=RETRY_COLOR, ) render_utils.revert_changes_for_frid(render_context) diff --git a/render_machine/render_context.py b/render_machine/render_context.py index b415aca1..fff78ebf 100644 --- a/render_machine/render_context.py +++ b/render_machine/render_context.py @@ -7,7 +7,7 @@ import plain_spec from codeplain_REST_api import CodeplainAPI from event_bus import EventBus -from plain2code_console import console +from plain2code_console import RETRY_COLOR, console from plain2code_events import RenderContextSnapshot from plain2code_state import RunState from plain_modules import PlainModule @@ -283,9 +283,11 @@ def _on_unit_test_limit_exceeded_in_conformance_tests(self): self.dispatch_error(error_msg) else: console.info( - f"Failed to adjust the unit tests after implementation code was updated while fixing the conformance tests for functionality {self.frid_context.frid}." + f"↻ Failed to adjust the unit tests after implementation code was updated while fixing the " + f"conformance tests for functionality {self.frid_context.frid}. " + f"Restarting rendering the functionality {self.frid_context.frid} from scratch.", + color=RETRY_COLOR, ) - console.info(f"Restarting rendering the functionality {self.frid_context.frid} from scratch.") self.machine.dispatch(triggers.RESTART_FRID_PROCESSING) def _on_unit_test_limit_exceeded_in_refactoring(self): diff --git a/render_machine/render_utils.py b/render_machine/render_utils.py index 3d3e8e1b..7e22e4c5 100644 --- a/render_machine/render_utils.py +++ b/render_machine/render_utils.py @@ -14,7 +14,7 @@ import file_utils import git_utils import plain_spec -from plain2code_console import console +from plain2code_console import MUTED_COLOR, RETRY_COLOR, SUCCESS_COLOR, console from plain2code_exceptions import RenderCancelledError SCRIPT_EXECUTION_TIMEOUT = 120 @@ -178,24 +178,30 @@ def _drain_stdout() -> None: temp_file.write(f"{script_type} script {script} successfully passed.\n") temp_file.write(f"{script_type} script execution time: {elapsed_time:.2f} seconds.\n") - console.debug(f"[#888888]{script_type} script output stored in: {temp_file_path.strip()}[/#888888]") + console.debug(f"{script_type} script output stored in: {temp_file_path.strip()}", color=MUTED_COLOR) if proc.returncode != 0: if frid is not None: - console.debug( - f"The {script_type} script for functionality ID {frid} of module {module} has failed. Initiating the patching mode to automatically correct the discrepancies." + console.info( + f"↻ The {script_type} script for functionality ID {frid} of module {module} has failed. " + f"Initiating the patching mode to automatically correct the discrepancies.", + color=RETRY_COLOR, ) else: - console.debug( - f"The {script_type} script has failed. Initiating the patching mode to automatically correct the discrepancies." + console.info( + f"↻ The {script_type} script has failed. " + f"Initiating the patching mode to automatically correct the discrepancies.", + color=RETRY_COLOR, ) else: if frid is not None: console.info( - f"[#79FC96]The {script_type} script for functionality ID {frid} of module {module} has passed successfully.[/#79FC96]" + f"✓ The {script_type} script for functionality ID {frid} of module {module} " + f"has passed successfully.", + color=SUCCESS_COLOR, ) else: - console.info(f"[#79FC96]All {script_type} scripts have passed successfully.[/#79FC96]") + console.info(f"✓ All {script_type} scripts have passed successfully.", color=SUCCESS_COLOR) return proc.returncode, sanitized_script_output, temp_file_path diff --git a/tests/test_console_log_styles.py b/tests/test_console_log_styles.py new file mode 100644 index 00000000..9d64a8fc --- /dev/null +++ b/tests/test_console_log_styles.py @@ -0,0 +1,112 @@ +"""Unit tests for colored log messages (console color param, log records, and event forwarding).""" + +import logging + +import plain2code_logger +from event_bus import EventBus +from plain2code_console import RETRY_COLOR, SUCCESS_COLOR, Plain2CodeConsole +from plain2code_events import LogMessageEmitted +from plain2code_logger import LoggingHandler +from plain2code_state import RunState + + +class RecordCapturingHandler(logging.Handler): + def __init__(self): + super().__init__() + self.records = [] + + def emit(self, record): + self.records.append(record) + + +def make_console_with_capture(): + console = Plain2CodeConsole() + console.quiet = True + handler = RecordCapturingHandler() + logger = logging.getLogger(plain2code_logger.LOGGER_NAME) + logger.addHandler(handler) + logger.setLevel(logging.DEBUG) + return console, handler + + +class TestConsoleColorParam: + """The color param must color terminal output only; log records carry plain text plus a log_color hint.""" + + def teardown_method(self): + logger = logging.getLogger(plain2code_logger.LOGGER_NAME) + for handler in list(logger.handlers): + if isinstance(handler, RecordCapturingHandler): + logger.removeHandler(handler) + + def test_info_with_color_logs_plain_text_and_color_hint(self): + console, handler = make_console_with_capture() + console.info("↻ Script failed. Retrying...", color=RETRY_COLOR) + + assert len(handler.records) == 1 + record = handler.records[0] + assert record.levelno == logging.INFO + assert record.getMessage() == "↻ Script failed. Retrying..." + assert record.log_color == RETRY_COLOR + + def test_debug_with_color_keeps_debug_level(self): + console, handler = make_console_with_capture() + console.debug("↻ Network error on attempt 1/4. Retrying in 3 seconds...", color=RETRY_COLOR) + + record = handler.records[0] + assert record.levelno == logging.DEBUG + assert record.log_color == RETRY_COLOR + + def test_color_never_appears_in_logged_message(self): + console, handler = make_console_with_capture() + console.info("✓ All scripts passed.", color=SUCCESS_COLOR) + + message = handler.records[0].getMessage() + assert "[#" not in message + assert "[/" not in message + + def test_no_color_defaults_to_none(self): + console, handler = make_console_with_capture() + console.info("plain info") + + assert handler.records[0].log_color is None + + def test_bracketed_error_text_prints_verbatim(self): + console, handler = make_console_with_capture() + console.quiet = False + with console.capture() as capture: + console.info("Error: [Errno 8] failed [/closing] tag", color=RETRY_COLOR) + assert "[Errno 8]" in capture.get() + assert "[/closing]" in capture.get() + + +class TestLoggingHandlerForwardsColor: + """LoggingHandler must forward the log_color record attribute into LogMessageEmitted.""" + + def _emit_and_capture(self, log_call): + run_state = RunState("test.plain") + event_bus = EventBus() + received = [] + event_bus.subscribe(LogMessageEmitted, received.append) + + logger = logging.getLogger(plain2code_logger.LOGGER_NAME) + handler = LoggingHandler(event_bus, run_state) + logger.addHandler(handler) + logger.setLevel(logging.DEBUG) + try: + log_call(logger) + finally: + logger.removeHandler(handler) + return received + + def test_color_hint_is_forwarded(self): + received = self._emit_and_capture(lambda logger: logger.info("↻ retrying", extra={"log_color": RETRY_COLOR})) + + assert len(received) == 1 + assert received[0].message == "↻ retrying" + assert received[0].log_color == RETRY_COLOR + + def test_missing_color_hint_defaults_to_none(self): + received = self._emit_and_capture(lambda logger: logger.info("plain message")) + + assert len(received) == 1 + assert received[0].log_color is None diff --git a/tui/components.py b/tui/components.py index 761a64d7..17c23e61 100644 --- a/tui/components.py +++ b/tui/components.py @@ -1,6 +1,7 @@ from enum import Enum from typing import Literal, Optional +from rich.markup import escape from textual.containers import Horizontal, Vertical, VerticalScroll from textual.message import Message from textual.timer import Timer @@ -502,12 +503,23 @@ def compose(self): class LogEntry(Vertical): """A single log entry that can be expanded to show details.""" - def __init__(self, logger_name: str, level: str, message: str, timestamp: str = "", **kwargs): + SUCCESS_KEYWORDS = ["completed", "success", "successfully", "passed", "done", "✓"] + + def __init__( + self, + logger_name: str, + level: str, + message: str, + timestamp: str = "", + log_color: Optional[str] = None, + **kwargs, + ): super().__init__(**kwargs) self.logger_name = logger_name self.level = level self.message = message self.timestamp = timestamp + self.log_color = log_color self.is_expanded = False self.classes = f"log-entry log-{level.lower()}" @@ -521,11 +533,13 @@ def compose(self): time_prefix = f"[#888888][{time_part}][/#888888] " if time_part else "" indent_spaces = len(f"[{time_part}] ") if time_part else 0 - message_body = self.message - if any( - keyword in self.message.lower() - for keyword in ["completed", "success", "successfully", "passed", "done", "✓"] - ): + # Log messages are plain text; escape them so square brackets in + # interpolated content (error texts, file names) don't parse as markup. + message_body = escape(self.message) + if self.log_color: + message_body = f"[{self.log_color}]{message_body}[/{self.log_color}]" + elif any(keyword in self.message.lower() for keyword in self.SUCCESS_KEYWORDS): + # Fallback for messages emitted without an explicit color. message_body = f"[green]✓[/green] {message_body}" if indent_spaces and "\n" in message_body: @@ -585,19 +599,19 @@ def _should_show_log(self, level: str) -> bool: min_priority = self.LOG_LEVELS.get(self.min_level, 0) return log_priority >= min_priority - async def add_log(self, logger_name: str, level: str, message: str, timestamp: str = ""): + async def add_log( + self, logger_name: str, level: str, message: str, timestamp: str = "", log_color: Optional[str] = None + ): """Add a new log entry.""" # Check if this is a success message that should have spacing before it - is_success_message = any( - keyword in message.lower() for keyword in ["completed", "success", "successfully", "passed", "done", "✓"] - ) + is_success_message = any(keyword in message.lower() for keyword in LogEntry.SUCCESS_KEYWORDS) # Add empty line before success messages if is_success_message: spacer = Static("", classes="log-spacer") await self.mount(spacer) - entry = LogEntry(logger_name, level, message, timestamp) + entry = LogEntry(logger_name, level, message, timestamp, log_color=log_color) # Only show if level is >= minimum level if not self._should_show_log(level): diff --git a/tui/plain2code_tui.py b/tui/plain2code_tui.py index 3035aa14..7db9128e 100644 --- a/tui/plain2code_tui.py +++ b/tui/plain2code_tui.py @@ -208,6 +208,7 @@ def on_log_message_emitted(self, event: LogMessageEmitted): event.level, event.message, event.timestamp, + event.log_color, ) except Exception as e: log_to_widget(