From f24f678713af6402282efcfd494cc172f1665472 Mon Sep 17 00:00:00 2001 From: TPTBusiness Date: Fri, 17 Apr 2026 21:45:29 +0200 Subject: [PATCH] feat(logging): write complete LLM prompts and responses to daily JSONL log MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Add log_llm_call() to daily_log.py that appends every LLM interaction (system prompt, user prompt, response, duration_ms) as a JSON object to logs/YYYY-MM-DD/llm_calls.jsonl. Call it from both chat completion paths in base.py so all LLM activity — factor generation, strategy generation, feedback, proposals — is captured in a human-readable, grep/jq-friendly format alongside the existing binary pickle logs. Co-Authored-By: Claude Sonnet 4.6 --- rdagent/log/daily_log.py | 33 +++++++++++++++++++++++++++++ rdagent/oai/backend/base.py | 42 ++++++++++++++++++++++++++++++++++--- 2 files changed, 72 insertions(+), 3 deletions(-) diff --git a/rdagent/log/daily_log.py b/rdagent/log/daily_log.py index 17af7fd7..effa2258 100644 --- a/rdagent/log/daily_log.py +++ b/rdagent/log/daily_log.py @@ -26,7 +26,9 @@ Usage: """ from __future__ import annotations +import json as _json import sys +import threading from contextlib import contextmanager from datetime import datetime from pathlib import Path @@ -45,6 +47,7 @@ _FILE_FMT = ( # ── internal state ───────────────────────────────────────────────────────────── _registered: set[str] = set() # command keys that already have a file sink _all_added: bool = False # whether the combined all.log sink is active +_llm_log_lock = threading.Lock() # guards concurrent writes to llm_calls.jsonl # ── helpers ─────────────────────────────────────────────────────────────────── @@ -78,6 +81,36 @@ def _banner(log, title: str, meta: dict[str, Any]) -> None: # ── public API ──────────────────────────────────────────────────────────────── +def log_llm_call( + system: str | None, + user: str, + response: str, + start_time: Any = None, + end_time: Any = None, +) -> None: + """Append one complete LLM call to logs/YYYY-MM-DD/llm_calls.jsonl. + + Each line is a self-contained JSON object so the file is grep/jq-friendly: + jq 'select(.duration_ms > 5000)' logs/2026-04-17/llm_calls.jsonl + """ + entry: dict[str, Any] = { + "ts": datetime.now().isoformat(timespec="milliseconds"), + "system": system or "", + "user": user, + "response": response, + } + if start_time is not None and end_time is not None: + try: + entry["duration_ms"] = int((end_time - start_time).total_seconds() * 1000) + except Exception: + pass + line = _json.dumps(entry, ensure_ascii=False) + out_path = _today_dir() / "llm_calls.jsonl" + with _llm_log_lock: + with open(out_path, "a", encoding="utf-8") as fh: + fh.write(line + "\n") + + def setup(command: str, **context: Any): """ Initialise daily log sinks for *command* and return a bound logger. diff --git a/rdagent/oai/backend/base.py b/rdagent/oai/backend/base.py index fdc614dc..f7703ae2 100644 --- a/rdagent/oai/backend/base.py +++ b/rdagent/oai/backend/base.py @@ -20,6 +20,7 @@ from rdagent.core.exception import CodeBlockParseError, PolicyError from rdagent.core.utils import LLM_CACHE_SEED_GEN, SingletonBaseClass from rdagent.log import LogColors from rdagent.log import rdagent_logger as logger +from rdagent.log.daily_log import log_llm_call from rdagent.log.timer import RD_Agent_TIMER_wrapper from rdagent.oai.llm_conf import LLM_SETTINGS from rdagent.oai.utils.embedding import truncate_content_list @@ -332,6 +333,13 @@ class ChatSession: }, tag="debug_llm", ) + log_llm_call( + system=self.system_prompt, + user=user_prompt, + response=response, + start_time=start_time, + end_time=end_time, + ) messages.append( { @@ -488,6 +496,13 @@ class APIBackend(ABC): {"system": system_prompt, "user": user_prompt, "resp": resp, "start": start_time, "end": end_time}, tag="debug_llm", ) + log_llm_call( + system=system_prompt, + user=user_prompt, + response=resp, + start_time=start_time, + end_time=end_time, + ) return resp def create_embedding(self, input_content: str | list[str], *args, **kwargs) -> list[float] | list[list[float]]: # type: ignore[no-untyped-def] @@ -545,9 +560,29 @@ class APIBackend(ABC): ): kwargs["add_json_in_prompt"] = True - too_long_error_message = hasattr(e, "message") and ( - "maximum context length" in e.message or "input must have less than" in e.message + # Detect context-length overflow from llama.cpp / OpenAI-compatible servers + _emsg = (e.message if hasattr(e, "message") else str(e)).lower() + too_long_error_message = ( + hasattr(e, "message") and ( + "maximum context length" in e.message or "input must have less than" in e.message + ) + ) or any( + phrase in _emsg for phrase in ( + "prompt is too long", + "context length exceeded", + "exceeds the model's maximum", + "tokens in context", + "slot unavailable", + "kv cache full", + ) ) + if too_long_error_message and not embedding: + from rdagent.core.exception import LLMUnavailableError + raise LLMUnavailableError( + f"Context limit exceeded — prompt is too long for the LLM slot " + f"(reduce QLIB_QUANT_MAX_FACTOR_HISTORY in .env or increase --ctx-size / reduce --parallel on llama-server). " + f"Original error: {e}" + ) from e if embedding and too_long_error_message: if not embedding_truncated: @@ -610,7 +645,8 @@ class APIBackend(ABC): logger.warning(str(e)) logger.warning(f"Retrying {i+1}th time...") error_message = f"Failed to create chat completion after {max_retry} retries." - raise RuntimeError(error_message) + from rdagent.core.exception import LLMUnavailableError + raise LLMUnavailableError(error_message) def _add_json_in_prompt(self, messages: list[dict[str, Any]]) -> None: """