RomanNum3ral
/
honcho
mirror of https://github.com/plastic-labs/honcho.git
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

fix: compact honcho logging (#836) 

* fix: compact honcho logging

* fix: guard ms/s metric formatting against non-numeric values

Only apply float formatting when the metric value is numeric so a
str value with an ms/s unit falls through to a plain string instead
of raising. Applied to both the compact and rich log paths.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>

---------

Co-authored-by: Vineeth Voruganti <13438633+VVoruganti@users.noreply.github.com>
Co-authored-by: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
This commit is contained in:
Rajat Ahuja 2026-06-23 15:55:03 -04:00 committed by GitHub
parent ab8c5aeaa3
commit 715d8a90b9
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
9 changed files with 74 additions and 49 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

1
.env.template
View File

@ -8,6 +8,7 @@
# Application Settings
# =============================================================================
LOG_LEVEL=INFO
PERFORMANCE_LOG_FORMAT=compact # compact|rich
# SESSION_OBSERVERS_LIMIT=10
# GET_CONTEXT_MAX_TOKENS=100000
# MAX_FILE_SIZE=5242880 # Bytes

1
config.toml.example
View File

@ -6,6 +6,7 @@
# Application-level settings
[app]
LOG_LEVEL = "INFO"
PERFORMANCE_LOG_FORMAT = "compact" # "compact" for single-line logs, "rich" for local panels
SESSION_OBSERVERS_LIMIT = 10
GET_CONTEXT_MAX_TOKENS = 100000
MAX_FILE_SIZE = 5242880 # 5MB

8
src/config.py
View File

@ -1353,6 +1353,7 @@ class AppSettings(HonchoSettings):
# Application-wide settings
LOG_LEVEL: str = "INFO"
PERFORMANCE_LOG_FORMAT: str = "compact"
SESSION_OBSERVERS_LIMIT: Annotated[int, Field(default=10, gt=0)] = 10
MAX_FILE_SIZE: Annotated[int, Field(default=5_242_880, gt=0)] = 5_242_880 # 5MB
GET_CONTEXT_MAX_TOKENS: Annotated[int, Field(default=100_000, gt=0, le=250_000)] = (
@ -1401,6 +1402,13 @@ class AppSettings(HonchoSettings):
raise ValueError(f"Invalid log level: {v}")
return log_level
@field_validator("PERFORMANCE_LOG_FORMAT")
def validate_performance_log_format(cls, v: str) -> str:
log_format = v.lower()
if log_format not in ["compact", "rich"]:
raise ValueError(f"Invalid performance log format: {v}")
return log_format
@model_validator(mode="after")
def propagate_namespace(self) -> "AppSettings":
"""Propagate top-level NAMESPACE to nested settings if not explicitly set."""

12
src/crud/document.py
View File

@ -1024,8 +1024,10 @@ async def is_rejected_duplicate(
# If new document has more or equal information, keep it and delete existing
if score_new >= score_existing:
logger.warning(
f"[DUPLICATE DETECTION] Deleting existing in favor of new. new='{doc.content}', existing='{existing_doc.content}'."
logger.debug(
"[DUPLICATE DETECTION] Deleting existing in favor of new. new=%r, existing=%r.",
doc.content,
existing_doc.content,
)
# Carry the reinforcement count forward so replacing a duplicate counts as
# another derivation rather than resetting times_derived to 1.
@ -1041,8 +1043,10 @@ async def is_rejected_duplicate(
# reinforcing the same document must not lose updates.
existing_doc.times_derived = models.Document.times_derived + 1
await db.flush()
logger.warning(
f"[DUPLICATE DETECTION] Rejecting new in favor of existing. new='{doc.content}', existing='{existing_doc.content}'."
logger.debug(
"[DUPLICATE DETECTION] Rejecting new in favor of existing. new=%r, existing=%r.",
doc.content,
existing_doc.content,
)
return True

4
src/deriver/enqueue.py
View File

@ -495,7 +495,7 @@ async def enqueue_dream(
is_in_progress = await db_session.scalar(in_progress_check)
if is_in_progress:
logger.info(
logger.debug(
"Skipping dream enqueue - already in progress: %s/%s/%s (type: %s)",
workspace_name,
observer,
@ -515,7 +515,7 @@ async def enqueue_dream(
is_pending = await db_session.scalar(pending_check)
if is_pending:
logger.info(
logger.debug(
"Dream already pending in queue: %s/%s/%s (type: %s)",
workspace_name,
observer,

6
src/dreamer/dream_scheduler.py
View File

@ -218,7 +218,7 @@ class DreamScheduler:
configuration = get_configuration(None, session, workspace)
if not configuration.dream.enabled:
logger.info(
logger.debug(
f"Dreams disabled for {workspace_name}/{session_name}, skipping dream"
)
return
@ -319,7 +319,7 @@ async def check_and_schedule_dream(
).total_seconds() / 3600
if hours_since_last_dream < settings.DREAM.MIN_HOURS_BETWEEN_DREAMS:
logger.info(
logger.debug(
f"Skipping dream for {collection.observer}/{collection.observed}: only {hours_since_last_dream:.1f} hours "
+ f"since last dream (minimum: {settings.DREAM.MIN_HOURS_BETWEEN_DREAMS})"
)
@ -359,7 +359,7 @@ async def check_and_schedule_dream(
)
)
if pending_exists:
logger.info(
logger.debug(
"Skipping dream schedule for %s/%s: pending dream already in queue",
collection.observer,
collection.observed,

2
src/reconciler/scheduler.py
View File

@ -264,5 +264,5 @@ class ReconcilerScheduler:
)
return False
logger.info("Enqueued reconciler task: %s", task.name)
logger.debug("Enqueued reconciler task: %s", task.name)
return True

4
src/reconciler/sync_vectors.py
View File

@ -728,7 +728,7 @@ async def run_vector_reconciliation_cycle() -> ReconciliationMetrics:
if not (embs_work or cleanup_work):
break
logger.info("Vector reconciliation cycle completed (pgvector mode)")
logger.debug("Vector reconciliation cycle completed (pgvector mode)")
return metrics
# External vector store mode - reconcile documents, embeddings, and cleanup
@ -755,5 +755,5 @@ async def run_vector_reconciliation_cycle() -> ReconciliationMetrics:
logger.debug("No work done, breaking reconciliation loop")
break
logger.info("Vector reconciliation cycle completed")
logger.debug("Vector reconciliation cycle completed")
return metrics

85
src/telemetry/logging.py
View File

@ -17,7 +17,6 @@ from rich.console import Console, Group, RenderableType
from rich.panel import Panel
from rich.table import Table
from rich.text import Text
from rich.tree import Tree
from src.config import settings
from src.telemetry.metrics_collector import append_metrics_to_file
@ -176,28 +175,6 @@ def format_reasoning_inputs_as_markdown(
return "\n".join(parts)
def log_representation(
representation: Representation,
) -> None:
"""
Log representation in a tree structure.
Args:
representation: Representation to log
"""
tree = Tree("📊 REPRESENTATION")
type_branch = tree.add(f"[bold cyan]EXPLICIT[/] ({len(representation.explicit)})")
for i, obs in enumerate(representation.explicit, 1):
type_branch.add(f"[dim]{i}.[/] {obs}")
type_branch = tree.add(f"[bold cyan]DEDUCTIVE[/] ({len(representation.deductive)})")
for i, obs in enumerate(representation.deductive, 1):
type_branch.add(f"[dim]{i}.[/] {obs}")
console.print(tree)
console.print()
def accumulate_metric(
task_name: str,
label: str,
@ -276,16 +253,20 @@ def log_performance_metrics(
task_slug: str,
task_name: str,
metrics: list[tuple[str, str | int | float, str]] | None = None,
title: str = "⚡ PERFORMANCE",
title: str = "PERFORMANCE",
) -> None:
"""
Log performance metrics in a clean table and optionally send to global collector.
Log performance metrics and optionally send them to the global collector.
PERFORMANCE_LOG_FORMAT=compact emits numeric metrics on one INFO line and
keeps large "blob" metrics at DEBUG. PERFORMANCE_LOG_FORMAT=rich prints the
local Rich panel, including blob metrics, for interactive readability.
Args:
task_slug: Slug of the task that generated these metrics
task_name: Name of the task that generated these metrics
metrics: Dictionary of metric names and (value, unit) tuples
title: Table title
metrics: List of (metric_name, value, unit) tuples
title: Prefix for the log line
"""
task_name = f"{task_slug}_{task_name}"
# No-op if metrics were evicted (due to MAX_ACCUMULATED_TASKS limit) and no
@ -300,7 +281,41 @@ def log_performance_metrics(
if COLLECT_METRICS_LOCAL:
append_metrics_to_file(task_slug, task_name, metrics)
# Remove metrics with "blob" unit type. They get printed separately below the table.
if settings.PERFORMANCE_LOG_FORMAT == "rich":
_log_performance_metrics_rich(task_name, metrics, title)
return
# Keep large text payloads out of the compact INFO summary.
blob_metrics: list[tuple[str, str | int | float, str]] = []
summary_parts: list[str] = []
for metric, value, unit in metrics:
if unit == "blob":
blob_metrics.append((metric, value, unit))
continue
if unit == "ms" and isinstance(value, int | float):
formatted_value = f"{value:.0f}ms"
elif unit == "s" and isinstance(value, int | float):
formatted_value = f"{value:.3f}s"
elif unit in ("", "tokens", "count", "id"):
formatted_value = str(value)
else:
formatted_value = f"{value}{unit}"
summary_parts.append(f"{metric}={formatted_value}")
if summary_parts:
logger.info("%s %s | %s", title, task_name, " | ".join(summary_parts))
else:
logger.info("%s %s", title, task_name)
for metric, value, _unit in blob_metrics:
logger.debug("%s %s :: %s\n%s", title, task_name, metric, value)
def _log_performance_metrics_rich(
task_name: str,
metrics: list[tuple[str, str | int | float, str]],
title: str,
) -> None:
blob_metrics: list[tuple[str, str | int | float, str]] = []
non_blob_metrics: list[tuple[str, str | int | float, str]] = []
for metric in metrics:
@ -317,24 +332,20 @@ def log_performance_metrics(
table.add_column("Unit", style="dim", width=8)
for metric, value, unit in non_blob_metrics:
if unit == "ms":
if unit == "ms" and isinstance(value, int | float):
formatted_value = f"{value:.0f}"
elif unit == "s":
elif unit == "s" and isinstance(value, int | float):
formatted_value = f"{value:.3f}"
else:
formatted_value = str(value)
table.add_row(metric.replace("_", " ").title(), formatted_value, unit)
# Build content for the panel
content_items: list[RenderableType] = [table]
if blob_metrics:
for metric, value, _unit in blob_metrics:
content_items.append(
Text.assemble(" ", (f"\n{metric}:", "bold"), " ")
)
content_items.append(Text(str(value)))
for metric, value, _unit in blob_metrics:
content_items.append(Text.assemble(" ", (f"\n{metric}:", "bold"), " "))
content_items.append(Text(str(value)))
panel = Panel(
Group(*content_items),