Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 6 additions & 2 deletions codeplain_REST_api.py
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -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
Expand Down
53 changes: 32 additions & 21 deletions plain2code_console.py
Original file line number Diff line number Diff line change
Expand Up @@ -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()
Expand All @@ -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:
Expand Down Expand Up @@ -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()

Expand Down
1 change: 1 addition & 0 deletions plain2code_events.py
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
1 change: 1 addition & 0 deletions plain2code_logger.py
Original file line number Diff line number Diff line change
Expand Up @@ -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:
Expand Down
4 changes: 2 additions & 2 deletions render_machine/actions/create_dist.py
Original file line number Diff line number Diff line change
@@ -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

Expand All @@ -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
3 changes: 2 additions & 1 deletion render_machine/actions/exit_with_error.py
Original file line number Diff line number Diff line change
Expand Up @@ -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:
Expand Down
6 changes: 4 additions & 2 deletions render_machine/actions/fix_conformance_test.py
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -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:
Expand Down
7 changes: 4 additions & 3 deletions render_machine/actions/render_functional_requirement.py
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand All @@ -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)
Expand Down
8 changes: 5 additions & 3 deletions render_machine/render_context.py
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -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):
Expand Down
22 changes: 14 additions & 8 deletions render_machine/render_utils.py
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -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

Expand Down
112 changes: 112 additions & 0 deletions tests/test_console_log_styles.py
Original file line number Diff line number Diff line change
@@ -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
Loading
Loading