Skip to content
Open
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
2 changes: 1 addition & 1 deletion CLAUDE.md
Original file line number Diff line number Diff line change
Expand Up @@ -100,7 +100,7 @@ See `CODESTYLE.md` for full details. Key rules:
- **Types**: Always add type hints. Use modern generics: `list[str]`, `dict[str, int]`, `str | None`.
- **Data containers**: Use Pydantic `BaseModel` (not `@dataclass`) for value objects; use `model_config = ConfigDict(frozen=True)` when immutability is wanted.
- **Visibility**: `_` prefix for all internal attributes/methods.
- **Logging**: Use `logging` module; never `print()`.
- **Logging**: Use `logging` module; never `print()`. Logs carry structure, not content — never log message bodies, tool-call arguments, response bodies, header values, or URL query strings at any level. Route payload detail through `common.payload_logging.log_payload` (gated by `LOG_PAYLOADS`) and sanitize URLs with `common.url_classification.sanitize_url_for_log`. See `CODESTYLE.md` §9.
- **Imports**: stdlib → third-party → local, explicit only (no `*` imports).

## Testing
Expand Down
5 changes: 3 additions & 2 deletions CODESTYLE.md
Original file line number Diff line number Diff line change
Expand Up @@ -177,8 +177,9 @@ Pick the level from what the record *means for the service*, not from how it rea

### Content rule (metadata over payload)

- Records at **every** level (DEBUG included) carry structure, not content: roles, counts/sizes, durations, tool/skill/deployment/model names, identifiers, statuses/outcomes, error codes and types, MIME types, HTTP status codes, header **names**, and URLs stripped to scheme/host/path.
- Never log message bodies, tool-call argument values, tool/LLM response bodies, attachment content, header **values**, or URL query strings/fragments. The rule is an allowlist: when in doubt, a value is content. (Payload debugging is gated behind the `LOG_PAYLOADS` switch — delivered by #436.)
- Records at **every** level (DEBUG included) carry structure, not content: roles, counts/sizes, durations, tool/skill/deployment/model names, identifiers, statuses/outcomes, error codes and types, MIME types, HTTP status codes, header **names**, and URLs stripped to scheme/host/path (use `common.url_classification.sanitize_url_for_log`).
- Never log message bodies, tool-call argument values, tool/LLM response bodies, attachment content, header **values**, or URL query strings/fragments. The rule is an allowlist: when in doubt, a value is content. This includes exception messages our own code raises — keep response bodies off them (e.g. `ToolErrorException.__str__` is structural; the body stays on the `error_message` attribute for the LLM/user channels).
- Payload debugging is gated behind the `LOG_PAYLOADS` switch: emit an unconditional structure summary, then pass the payload through `common.payload_logging.log_payload` (a no-op unless `LOG_PAYLOADS=true`, truncating each field). Never log payload content unconditionally.
- Lifecycle-skeleton records use `common.lifecycle_logging.format_event` — a stable prefix plus `key=value` fields — so structured output (#438) and request ids (#439) can enrich them later without rewording.

---
Expand Down
21 changes: 21 additions & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -136,6 +136,8 @@ Controls which tool-execution stages are surfaced in the DIAL UI for each app. S
| `LOG_DATE_FORMAT` | `%Y-%m-%d %H:%M:%S` | No | `strftime`-style format for the `%(asctime)s` field |
| `LOG_LEVEL` | `INFO` | No | Root logger level (all loggers except quickapp) |
| `QUICKAPP_LOG_LEVEL` | `INFO` | No | Log level for quickapp loggers |
| `LOG_PAYLOADS` | `false` | No | Emit payload content (message bodies, tool-call arguments, tool/LLM response bodies) at DEBUG. When `false`, no payload content is logged at **any** level and the payload-capable third-party loggers (`openai`/`httpx`/`httpcore`) are capped at INFO. **Local development only** — see [Payload Logging](#payload-logging). |
| `LOG_PAYLOADS_MAX_LENGTH` | `2000` | No | Per-field character cap applied to each payload value when `LOG_PAYLOADS=true`; longer values are truncated. Inert when `LOG_PAYLOADS=false`. |
| **Agent** | | | |
| `DEFAULT_AGENT_MAX_ITERATIONS` | `15` | No | Maximum number of orchestrator iterations (`-1` for infinite) |
| `DEFAULT_ORCHESTRATOR_DEPLOYMENT_ID` | — | No | Default DIAL deployment id used as the orchestrator model when a QuickApp manifest omits `orchestrator.deployment`. Also surfaces as the JSON-schema `default` for that field so DIAL Core can pre-fill new manifests. Apps can override per-app. |
Expand Down Expand Up @@ -233,6 +235,25 @@ not strictly valid JSON. For guaranteed-valid structured logs, plug in a dedicat

</details>

#### Payload Logging

By policy, logs carry **structure** — roles, counts, sizes, names, ids, statuses, durations, HTTP codes,
header **names**, and URLs stripped to scheme/host/path — and never **content**: message bodies, tool-call
argument values, tool/LLM response bodies, attachment content, header **values**, or URL query strings. This
holds at every level, DEBUG included, so raising verbosity during an incident never brings conversation
content into the logs.

`LOG_PAYLOADS=true` is the single, explicit exception: it re-enables the payload-bearing DEBUG records (message
context, tool-call arguments, raw responses), each field truncated to `LOG_PAYLOADS_MAX_LENGTH`, and lifts the
INFO cap on the wire-level third-party loggers (`openai`, `httpx`, `httpcore`). Forwarded header **values** are
never logged, even with the switch on. The switch is additive to the level — content appears only when
`QUICKAPP_LOG_LEVEL=DEBUG` **and** `LOG_PAYLOADS=true`.

> [!CAUTION]
> `LOG_PAYLOADS` is intended for **local development only**. It writes conversation content and wire-level
> third-party payloads to the log pipeline (including any OTLP export). Do **not** enable it in shared or
> production environments.

## Local Development

### Pre-requisites
Expand Down
9 changes: 9 additions & 0 deletions docs/agent.md
Original file line number Diff line number Diff line change
Expand Up @@ -136,6 +136,15 @@ request did during an incident without raising verbosity or exposing conversatio
Events are formatted by `common.lifecycle_logging.format_event` as a stable prefix plus `key=value` fields.
A handled tool failure produces exactly one `WARNING` (the failure) plus the fallback and completion `INFO`
events; an unhandled failure adds the single `ERROR` (with `error_reference`) owned by `_QuickAppCompletion`.

**Content rule.** At every level (DEBUG included) records carry structure — roles, counts, sizes, names, ids,
statuses, durations, header **names**, and URLs stripped to scheme/host/path — never message bodies, tool-call
arguments, response bodies, header values, or URL query strings. Payload dumps in the agent loop and toolsets
emit an unconditional structure summary and route the payload through `common.payload_logging.log_payload`,
which is a no-op (and truncates) unless `LOG_PAYLOADS=true`. The switch also lifts the INFO cap that
`LoggingConfig` otherwise applies to the wire-level third-party loggers (`openai`/`httpx`/`httpcore`), so
raising a log level alone never brings payloads into the pipeline.

Level semantics, the single-writer ERROR rule, and the content policy live in `CODESTYLE.md` §9 and
[`docs/designs/log_levels_and_content_policy.md`](designs/log_levels_and_content_policy.md).

Expand Down
3 changes: 2 additions & 1 deletion docs/designs/log_levels_and_content_policy.md
Original file line number Diff line number Diff line change
@@ -1,7 +1,8 @@
# Design: Log Levels & Content Policy

- **Status:** Approved
- **Status:** Implemented
- **Approved:** 2026-07-14
- **Implemented:** 2026-07-17 ([#435](https://github.com/epam/ai-dial-quickapps-backend/issues/435) lifecycle skeleton + level rebalance; [#436](https://github.com/epam/ai-dial-quickapps-backend/issues/436) content rule + payload switch)
- **Issue:** [#434](https://github.com/epam/ai-dial-quickapps-backend/issues/434) (epic [#441](https://github.com/epam/ai-dial-quickapps-backend/issues/441))
- **Dependencies:**
- None. Informed by the logging review of 2026-07-13. Gates the implementation issues
Expand Down
43 changes: 25 additions & 18 deletions src/quickapp/common/chat_completion_stream/handler.py
Original file line number Diff line number Diff line change
Expand Up @@ -31,6 +31,7 @@
ChatStreamAccumulator,
ensure_attachment_url_or_data,
)
from quickapp.common.payload_logging import log_payload

logger = logging.getLogger(__name__)

Expand Down Expand Up @@ -178,8 +179,9 @@ def _stream_stage_delta(
if stage is None:
if not stage_name:
logger.warning(
"Skipping stage delta propagation because stage name is missing: %s", delta
"Skipping stage delta propagation because stage name is missing (index=%s)", idx
)
log_payload(logger, "Stage delta with missing name: %s", delta)
return
try:
stage = dest.create_stage(stage_name)
Expand Down Expand Up @@ -258,23 +260,28 @@ def _close_all_streaming_stages(

@staticmethod
def _log_stream_accumulator(result: ChatStreamAccumulator) -> None:
logger.debug("===================")
logger.debug(" ---- Captured values:")
logger.debug(" ----- text llm response: %s", result.content)
if result.tool_calls:
logger.debug(" ------ tool_calls:")
for tool in result.tool_calls:
logger.debug(" -------- %s - %s - %s", tool.name, tool.arguments, tool)
tool_calls = result.tool_calls # property rebuilds a list on each access
logger.debug(
"LLM response accumulated: content_length=%d, tool_calls=%s, attachments=%d, "
"stages=%d, state_keys=%s, usage=%s",
len(result.content),
[tool.name for tool in tool_calls] if tool_calls else [],
len(result.attachments),
len(result.stages),
list(result.state) if result.state else [],
(
f"{result.usage.prompt_tokens}/{result.usage.completion_tokens}"
if result.usage
else None
),
)
if result.content:
log_payload(logger, "LLM response content: %s", result.content)
for tool in tool_calls or []:
log_payload(logger, "LLM tool call args (%s): %s", tool.name, tool.arguments)
if result.attachments:
logger.debug(" ------ attachments: %s", result.attachments)
log_payload(logger, "LLM response attachments: %s", result.attachments)
if result.stages:
logger.debug(" ------ stages: %s", result.stages)
log_payload(logger, "LLM response stages: %s", result.stages)
if result.state:
logger.debug(" ------ state: %s", result.state)
if result.usage:
logger.debug(
" ------ usage: prompt_tokens=%s completion_tokens=%s",
result.usage.prompt_tokens,
result.usage.completion_tokens,
)
logger.debug("===================")
log_payload(logger, "LLM response state: %s", result.state)
21 changes: 19 additions & 2 deletions src/quickapp/common/exceptions/tool_error.py
Original file line number Diff line number Diff line change
@@ -1,7 +1,24 @@
class ToolErrorException(Exception):
"""Raised when a tool call returns an error."""
"""Raised when a tool call returns an error.

The exception *message* (``str(e)``, used in logs and tracebacks) carries only
structure — the content rule (issue #436) keeps the tool response body out of the log
pipeline. The body stays available on the :attr:`error_message` attribute, which the
fallback machinery may forward to the LLM (``forward_tool_error_message``, #408) and
the error resolver may surface to the user; neither is a log channel.

The structural string form is owned here so no subclass can accidentally embed the
body: subclasses set :attr:`tool_kind` (the human label) and the base builds the
message. ``str(e)`` returns this message (the sole ``Exception`` arg), so logs and
tracebacks never carry the body.
"""

tool_kind = "Tool"

def __init__(self, tool_name: str, error_message: str):
super().__init__(f"Tool '{tool_name}' returned an error: {error_message}")
super().__init__(
f"{self.tool_kind} '{tool_name}' returned an error "
f"(content_length={len(error_message)})"
)
self.tool_name = tool_name
self.error_message = error_message
81 changes: 81 additions & 0 deletions src/quickapp/common/payload_logging.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,81 @@
"""The payload-debugging switch (content policy, design #434 / issue #436).

The content rule (enforced everywhere else, see ``common.lifecycle_logging``) keeps
message bodies, tool-call arguments, and response payloads out of the logs at every
level. This module is the single, deliberate exception: the one place allowed to render
payload content, and only behind the ``LOG_PAYLOADS`` opt-in, with each field truncated.

Because ``LoggingSettings`` is consumed once at startup and not kept in the DI graph
(``LoggingConfig`` applies it and discards it), the switch state lives here as module-level
config, set once by ``LoggingConfig`` via :func:`configure_payload_logging`. Callers read it
through :func:`payloads_enabled` / :func:`log_payload` without touching settings. The module
takes primitives rather than ``LoggingSettings`` so ``common`` stays free of a ``config``
import.
"""

import logging
from collections import Counter
from collections.abc import Iterable, Mapping
from typing import Any

_DEFAULT_MAX_LENGTH = 2000
_TRUNCATION_MARKER = "…[truncated]"

_enabled = False
_max_length = _DEFAULT_MAX_LENGTH


def configure_payload_logging(enabled: bool, max_length: int) -> None:
"""Apply the ``LOG_PAYLOADS`` / ``LOG_PAYLOADS_MAX_LENGTH`` settings.

Called once at startup by ``LoggingConfig``. Tests may call it directly (and should
restore the defaults afterwards).
"""
global _enabled, _max_length
_enabled = enabled
_max_length = max_length


def payloads_enabled() -> bool:
"""Whether payload-bearing records may be emitted (``LOG_PAYLOADS=true``)."""
return _enabled


def _truncate(value: Any) -> str:
"""Render ``value`` as a string capped at the configured max length.

Longer values are cut and marked with an ellipsis so a truncated payload is never
mistaken for the whole thing.
"""
text = value if isinstance(value, str) else str(value)
if len(text) <= _max_length:
return text
return text[:_max_length] + _TRUNCATION_MARKER


def log_payload(logger: logging.Logger, msg: str, *args: Any) -> None:
"""Emit a payload-bearing DEBUG record, but only when ``LOG_PAYLOADS`` is on.

Each ``%s`` argument is truncated to the configured cap. A no-op (nothing is rendered
or emitted) when the switch is off, so callers can pair it with an unconditional
structure summary without guarding it themselves.
"""
if not _enabled:
return
logger.debug(msg, *(_truncate(arg) for arg in args))


def summarize_roles(messages: Iterable[Any]) -> Counter[str]:
"""Count messages by ``role`` — a structure summary that carries no message bodies.

Handles both message objects (``message.role``) and serialized message dicts
(``message["role"]``); a missing role falls under ``"unknown"``. The resulting
``Counter`` renders as ``Counter({role: count})``.
"""

def _role(message: Any) -> str:
if isinstance(message, Mapping):
return str(message.get("role") or "unknown")
return str(getattr(message, "role", None) or "unknown")

return Counter(_role(message) for message in messages)
9 changes: 8 additions & 1 deletion src/quickapp/common/staged_base_tool.py
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@
from quickapp.common.abstract.base_tool_argument_transformer import ToolArgumentTransformer
from quickapp.common.base_stage_wrapper import BaseStageWrapper
from quickapp.common.lifecycle_logging import format_duration, format_event
from quickapp.common.payload_logging import log_payload
from quickapp.common.stage_close_registry import (
DeferredStageCloseRegistry,
ImmediateStageCloseRegistry,
Expand Down Expand Up @@ -198,7 +199,13 @@ async def _run_in_stage_report_success(
if matches_type(a.type, attachment_cfg.propagate_types_to_choice):
result.propagate_to_choice.append(a)
result.attachments = filtered
logger.debug(f"Tool call {tool_call_id} finished with result {result}")
logger.debug(
"Tool call %s finished: content_length=%d, attachments=%d",
tool_call_id,
len(result.content) if result.content else 0,
len(result.attachments) if result.attachments else 0,
)
log_payload(logger, "Tool call %s result: %s", tool_call_id, result)
logger.info(
format_event(
"Tool call completed",
Expand Down
8 changes: 6 additions & 2 deletions src/quickapp/common/state_holder.py
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,8 @@
from aidial_sdk.chat_completion import Attachment, ToolCall
from pydantic import BaseModel, Field, PrivateAttr

from quickapp.common.payload_logging import log_payload

logger = logging.getLogger(__name__)


Expand All @@ -17,11 +19,13 @@ class StateHolder(BaseModel):
_file_metadata_dict: dict[str, FileMetadata] = PrivateAttr(default_factory=dict)

def add_state(self, key: str, value: Any) -> None:
logger.debug(f"Added state [{key}]={value}")
logger.debug("Added state [%s] (type=%s)", key, type(value).__name__)
log_payload(logger, "Added state [%s]=%s", key, value)
self._state[key] = value

def get_state(self) -> dict[str, Any]:
logger.debug(f"Read state {self._state}")
logger.debug("Read state keys: %s", list(self._state))
log_payload(logger, "Read state: %s", self._state)
return self._state

def get_file_data(self, url: str | None = None, key: str | None = None) -> bytes | None:
Expand Down
19 changes: 15 additions & 4 deletions src/quickapp/common/tool_fallback/applicable_mixin.py
Original file line number Diff line number Diff line change
@@ -1,3 +1,4 @@
from quickapp.common.exceptions.tool_error import ToolErrorException
from quickapp.config.tools.tool_fallback import ToolFallbackStrategyModel, TriggerOn, TriggerOnType


Expand All @@ -11,17 +12,27 @@ def _is_applicable(strategy_config: ToolFallbackStrategyModel, error: Exception)
return False
return True

@staticmethod
def _matchable_text(error: Exception) -> str:
# Match trigger_on against the real tool error body (error_message), not the
# structural str(e): the exception's string form carries no response body under
# the content rule (#436), but trigger matching must still see the error text.
if isinstance(error, ToolErrorException):
return error.error_message
return str(error)

@staticmethod
def _is_applicable_by_trigger_on(trigger_on: TriggerOn, error: Exception) -> bool:
text = ApplicableStrategyMixin._matchable_text(error)
if trigger_on.type == TriggerOnType.contains:
return (
trigger_on.value in str(error)
trigger_on.value in text
if trigger_on.case_sensitive
else trigger_on.value.lower() in str(error).lower()
else trigger_on.value.lower() in text.lower()
)
else:
return (
trigger_on.value == str(error)
trigger_on.value == text
if trigger_on.case_sensitive
else trigger_on.value.lower() == str(error).lower()
else trigger_on.value.lower() == text.lower()
)
Loading
Loading