diff --git a/README.md b/README.md index 61116fa1..ec4ff77a 100644 --- a/README.md +++ b/README.md @@ -13,6 +13,7 @@ ## Table of Contents +- [What's new (2026-06-22) — Canonical Log Lines & Structured Logging](#whats-new-2026-06-22--canonical-log-lines--structured-logging) - [What's new (2026-06-22) — Conditional HTTP Requests & Cache Validators](#whats-new-2026-06-22--conditional-http-requests--cache-validators) - [What's new (2026-06-22) — Cookie Jar (HTTP Session Carry)](#whats-new-2026-06-22--cookie-jar-http-session-carry) - [What's new (2026-06-22) — HTTP Content Negotiation & Decompression](#whats-new-2026-06-22--http-content-negotiation--decompression) @@ -145,6 +146,12 @@ --- +## What's new (2026-06-22) — Canonical Log Lines & Structured Logging + +One wide event per run, with trace correlation. Full reference: [`docs/source/Eng/doc/new_features/v93_features_doc.rst`](docs/source/Eng/doc/new_features/v93_features_doc.rst). + +- **`CanonicalLogLine` / `JSONLogFormatter` / `bind_trace_context`** (`AC_canonical_log`): `logging_instance` emits a fixed pipe-delimited string with no JSON and no trace/span fields. This adds a Stripe-style canonical log line (field accumulator + `timer` with injectable clock) and a JSON `logging.Formatter` that carries `trace_id`/`span_id` — the log-trace correlation counterpart to `trace_context`. Pure-stdlib, deterministic. + ## What's new (2026-06-22) — Conditional HTTP Requests & Cache Validators Skip re-downloading unchanged resources (ETag / 304). Full reference: [`docs/source/Eng/doc/new_features/v92_features_doc.rst`](docs/source/Eng/doc/new_features/v92_features_doc.rst). diff --git a/README/README_zh-CN.md b/README/README_zh-CN.md index cd522447..8b339657 100644 --- a/README/README_zh-CN.md +++ b/README/README_zh-CN.md @@ -12,6 +12,7 @@ ## 目录 +- [本次更新 (2026-06-22) — 标准日志行与结构化日志](#本次更新-2026-06-22--标准日志行与结构化日志) - [本次更新 (2026-06-22) — 条件式 HTTP 请求与缓存验证子](#本次更新-2026-06-22--条件式-http-请求与缓存验证子) - [本次更新 (2026-06-22) — Cookie Jar(HTTP 会话携带)](#本次更新-2026-06-22--cookie-jarhttp-会话携带) - [本次更新 (2026-06-22) — HTTP 内容协商与解压](#本次更新-2026-06-22--http-内容协商与解压) @@ -144,6 +145,12 @@ --- +## 本次更新 (2026-06-22) — 标准日志行与结构化日志 + +每次执行一行宽事件,并带 trace 关联。完整参考:[`docs/source/Zh/doc/new_features/v93_features_doc.rst`](../docs/source/Zh/doc/new_features/v93_features_doc.rst)。 + +- **`CanonicalLogLine` / `JSONLogFormatter` / `bind_trace_context`**(`AC_canonical_log`):`logging_instance` 输出固定的管线分隔字符串,没有 JSON 也没有 trace/span 字段。本功能加入 Stripe 风格的标准日志行(字段累积器 + 可注入时钟的 `timer`)以及携带 `trace_id`/`span_id` 的 JSON `logging.Formatter` —— 与 `trace_context` 对应的 log-trace 关联。纯标准库、确定。 + ## 本次更新 (2026-06-22) — 条件式 HTTP 请求与缓存验证子 跳过重新下载未变更的资源(ETag / 304)。完整参考:[`docs/source/Zh/doc/new_features/v92_features_doc.rst`](../docs/source/Zh/doc/new_features/v92_features_doc.rst)。 diff --git a/README/README_zh-TW.md b/README/README_zh-TW.md index 82db1fa4..a6dc79f1 100644 --- a/README/README_zh-TW.md +++ b/README/README_zh-TW.md @@ -12,6 +12,7 @@ ## 目錄 +- [本次更新 (2026-06-22) — 標準日誌行與結構化日誌](#本次更新-2026-06-22--標準日誌行與結構化日誌) - [本次更新 (2026-06-22) — 條件式 HTTP 請求與快取驗證子](#本次更新-2026-06-22--條件式-http-請求與快取驗證子) - [本次更新 (2026-06-22) — Cookie Jar(HTTP 工作階段攜帶)](#本次更新-2026-06-22--cookie-jarhttp-工作階段攜帶) - [本次更新 (2026-06-22) — HTTP 內容協商與解壓縮](#本次更新-2026-06-22--http-內容協商與解壓縮) @@ -144,6 +145,12 @@ --- +## 本次更新 (2026-06-22) — 標準日誌行與結構化日誌 + +每次執行一行寬事件,並帶 trace 關聯。完整參考:[`docs/source/Zh/doc/new_features/v93_features_doc.rst`](../docs/source/Zh/doc/new_features/v93_features_doc.rst)。 + +- **`CanonicalLogLine` / `JSONLogFormatter` / `bind_trace_context`**(`AC_canonical_log`):`logging_instance` 輸出固定的管線分隔字串,沒有 JSON 也沒有 trace/span 欄位。本功能加入 Stripe 風格的標準日誌行(欄位累積器 + 可注入時鐘的 `timer`)以及攜帶 `trace_id`/`span_id` 的 JSON `logging.Formatter` —— 與 `trace_context` 對應的 log-trace 關聯。純標準函式庫、具決定性。 + ## 本次更新 (2026-06-22) — 條件式 HTTP 請求與快取驗證子 略過重新下載未變更的資源(ETag / 304)。完整參考:[`docs/source/Zh/doc/new_features/v92_features_doc.rst`](../docs/source/Zh/doc/new_features/v92_features_doc.rst)。 diff --git a/docs/source/Eng/doc/new_features/v93_features_doc.rst b/docs/source/Eng/doc/new_features/v93_features_doc.rst new file mode 100644 index 00000000..446d22fb --- /dev/null +++ b/docs/source/Eng/doc/new_features/v93_features_doc.rst @@ -0,0 +1,45 @@ +Canonical Log Lines & Structured Logging +======================================== + +``logging_instance`` emits a fixed pipe-delimited human string with no JSON +option and no trace/span fields, but OTel log-trace correlation needs +``trace_id`` / ``span_id`` on each record. This adds a Stripe-style canonical +log line (one wide field-bag emitted per run) and a JSON ``logging.Formatter`` +that carries trace context. + +Pure standard library (``json`` / ``logging``); imports no ``PySide6``. The +timer clock is injectable, so durations are deterministic in CI. + +Headless API +------------ + +.. code-block:: python + + from je_auto_control import ( + CanonicalLogLine, bind_trace_context, JSONLogFormatter, + new_root_context, + ) + + line = CanonicalLogLine({"event": "run_suite"}) + bind_trace_context(line, new_root_context()) + with line.timer("execute"): + run() + line.add("ok", True).emit(logger.info) # one wide line per run + + # structured logging with trace correlation: + handler.setFormatter(JSONLogFormatter()) + +``CanonicalLogLine`` accumulates request-scoped fields (``add`` / ``update``), +times a block into ``{name}_ms`` via ``timer`` (injectable clock), and +``render`` / ``emit`` the wide line as JSON. ``bind_trace_context`` attaches a +``SpanContext``'s ``trace_id`` / ``span_id``. ``JSONLogFormatter`` is a +``logging.Formatter`` that emits one JSON object per record including +``trace_id`` / ``span_id`` and any ``extra=`` fields — the log-trace correlation +counterpart to ``trace_context``. + +Executor command +---------------- + +``AC_canonical_log`` builds a canonical line from a ``fields`` object and returns +``{line, json}``. It is exposed as the MCP tool ``ac_canonical_log`` and as a +Script Builder command under **Report**. diff --git a/docs/source/Eng/eng_index.rst b/docs/source/Eng/eng_index.rst index 8e82f7eb..b67ba055 100644 --- a/docs/source/Eng/eng_index.rst +++ b/docs/source/Eng/eng_index.rst @@ -115,6 +115,7 @@ Comprehensive guides for all AutoControl features. doc/new_features/v90_features_doc doc/new_features/v91_features_doc doc/new_features/v92_features_doc + doc/new_features/v93_features_doc doc/ocr_backends/ocr_backends_doc doc/observability/observability_doc doc/operations_layer/operations_layer_doc diff --git a/docs/source/Zh/doc/new_features/v93_features_doc.rst b/docs/source/Zh/doc/new_features/v93_features_doc.rst new file mode 100644 index 00000000..762b4875 --- /dev/null +++ b/docs/source/Zh/doc/new_features/v93_features_doc.rst @@ -0,0 +1,39 @@ +標準日誌行與結構化日誌 +==================== + +``logging_instance`` 輸出固定的管線分隔人類字串,沒有 JSON 選項也沒有 trace/span 欄位,但 OTel 的 +log-trace 關聯需要每筆記錄都帶 ``trace_id`` / ``span_id``。本功能加入 Stripe 風格的標準日誌行(每次執行 +輸出一個寬欄位包)以及一個攜帶 trace 脈絡的 JSON ``logging.Formatter``。 + +純標準函式庫(``json`` / ``logging``);不匯入 ``PySide6``。計時器時鐘可注入,因此時長在 CI 中具決定性。 + +無頭 API +-------- + +.. code-block:: python + + from je_auto_control import ( + CanonicalLogLine, bind_trace_context, JSONLogFormatter, + new_root_context, + ) + + line = CanonicalLogLine({"event": "run_suite"}) + bind_trace_context(line, new_root_context()) + with line.timer("execute"): + run() + line.add("ok", True).emit(logger.info) # 每次執行一行寬事件 + + # 帶 trace 關聯的結構化日誌: + handler.setFormatter(JSONLogFormatter()) + +``CanonicalLogLine`` 累積請求範圍的欄位(``add`` / ``update``),透過 ``timer``(可注入時鐘)把一段區塊 +計入 ``{name}_ms``,並以 ``render`` / ``emit`` 將寬事件行輸出為 JSON。``bind_trace_context`` 附上 +``SpanContext`` 的 ``trace_id`` / ``span_id``。``JSONLogFormatter`` 是一個 ``logging.Formatter``,每筆記錄 +輸出一個 JSON 物件,包含 ``trace_id`` / ``span_id`` 與任何 ``extra=`` 欄位 —— 與 ``trace_context`` 對應的 +log-trace 關聯。 + +執行器命令 +---------- + +``AC_canonical_log`` 從 ``fields`` 物件建立標準日誌行,回傳 ``{line, json}``。它以 MCP 工具 +``ac_canonical_log`` 以及 Script Builder 中 **Report** 分類下的命令提供。 diff --git a/docs/source/Zh/zh_index.rst b/docs/source/Zh/zh_index.rst index aaf476cc..7554a151 100644 --- a/docs/source/Zh/zh_index.rst +++ b/docs/source/Zh/zh_index.rst @@ -115,6 +115,7 @@ AutoControl 所有功能的完整使用指南。 doc/new_features/v90_features_doc doc/new_features/v91_features_doc doc/new_features/v92_features_doc + doc/new_features/v93_features_doc doc/ocr_backends/ocr_backends_doc doc/observability/observability_doc doc/operations_layer/operations_layer_doc diff --git a/je_auto_control/__init__.py b/je_auto_control/__init__.py index 75ab94e5..d277e374 100644 --- a/je_auto_control/__init__.py +++ b/je_auto_control/__init__.py @@ -446,6 +446,10 @@ from je_auto_control.utils.baggage import ( Baggage, extract_baggage, format_baggage, inject_baggage, parse_baggage, ) +# Canonical (wide-event) log lines + structured JSON logging +from je_auto_control.utils.canonical_log import ( + CanonicalLogLine, JSONLogFormatter, bind_trace_context, +) # Background popup/interrupt watchdog (unattended automation) from je_auto_control.utils.watchdog import ( PopupWatchdog, WatchdogRule, default_popup_watchdog, @@ -971,6 +975,7 @@ def start_autocontrol_gui(*args, **kwargs): "parse_tracestate", "Baggage", "extract_baggage", "format_baggage", "inject_baggage", "parse_baggage", + "CanonicalLogLine", "JSONLogFormatter", "bind_trace_context", # MCP server "AuditLogger", "HttpMCPServer", "MCPContent", "MCPPrompt", "MCPPromptArgument", "MCPResource", "MCPServer", "MCPTool", diff --git a/je_auto_control/gui/script_builder/command_schema.py b/je_auto_control/gui/script_builder/command_schema.py index 33845730..f5437d77 100644 --- a/je_auto_control/gui/script_builder/command_schema.py +++ b/je_auto_control/gui/script_builder/command_schema.py @@ -1640,6 +1640,14 @@ def _add_resilience_specs(specs: List[CommandSpec]) -> None: ), description="Serialise items into a percent-encoded baggage header.", )) + specs.append(CommandSpec( + "AC_canonical_log", "Report", "Canonical Log: Build Line", + fields=( + FieldSpec("fields", FieldType.STRING, + placeholder='{"event": "run", "ok": true, "ms": 42}'), + ), + description="Build a canonical wide-event log line (rendered as JSON).", + )) specs.append(CommandSpec( "AC_resolve_ref", "Security", "Secret Ref: Resolve", fields=( diff --git a/je_auto_control/utils/canonical_log/__init__.py b/je_auto_control/utils/canonical_log/__init__.py new file mode 100644 index 00000000..9f30e17e --- /dev/null +++ b/je_auto_control/utils/canonical_log/__init__.py @@ -0,0 +1,6 @@ +"""Canonical log lines and structured JSON logging for AutoControl.""" +from je_auto_control.utils.canonical_log.canonical_log import ( + CanonicalLogLine, JSONLogFormatter, bind_trace_context, +) + +__all__ = ["CanonicalLogLine", "JSONLogFormatter", "bind_trace_context"] diff --git a/je_auto_control/utils/canonical_log/canonical_log.py b/je_auto_control/utils/canonical_log/canonical_log.py new file mode 100644 index 00000000..25f16cc0 --- /dev/null +++ b/je_auto_control/utils/canonical_log/canonical_log.py @@ -0,0 +1,84 @@ +"""Canonical (wide-event) log lines and structured JSON log formatting. + +``logging_instance`` emits a fixed pipe-delimited human string with no JSON +option and no trace/span fields, but OTel log-trace correlation needs +``trace_id`` / ``span_id`` on each record. This adds a Stripe-style canonical +log line (one wide field-bag emitted per run) and a JSON ``logging.Formatter`` +that carries trace context. + +Pure standard library (``json`` / ``logging``); imports no ``PySide6``. The +timer clock is injectable, so durations are deterministic in CI. +""" +import json +import logging +import time +from contextlib import contextmanager +from typing import Any, Callable, Dict, Iterator, Mapping, Optional + +_STANDARD = frozenset(vars(logging.makeLogRecord({}))) + + +class CanonicalLogLine: + """A request-scoped accumulator emitting one wide log line.""" + + def __init__(self, fields: Optional[Mapping[str, Any]] = None, *, + clock: Callable[[], float] = time.monotonic) -> None: + self._fields: Dict[str, Any] = dict(fields or {}) + self._clock = clock + + def add(self, key: str, value: Any) -> "CanonicalLogLine": + """Add or overwrite one field; returns self for chaining.""" + self._fields[str(key)] = value + return self + + def update(self, mapping: Mapping[str, Any]) -> "CanonicalLogLine": + """Merge a mapping of fields.""" + for key, value in mapping.items(): + self._fields[str(key)] = value + return self + + @contextmanager + def timer(self, name: str) -> Iterator[None]: + """Time a block, recording ``{name}_ms`` on completion.""" + start = self._clock() + try: + yield + finally: + self._fields[f"{name}_ms"] = round((self._clock() - start) * 1000, 3) + + def to_dict(self) -> Dict[str, Any]: + """Return the accumulated fields.""" + return dict(self._fields) + + def render(self) -> str: + """Render the line as a single JSON object (sorted keys).""" + return json.dumps(self._fields, sort_keys=True, default=str) + + def emit(self, sink: Callable[[Dict[str, Any]], Any]) -> "CanonicalLogLine": + """Send the field dict to ``sink`` (e.g. a logger or a list append).""" + sink(self.to_dict()) + return self + + +def bind_trace_context(line: CanonicalLogLine, + context: Any) -> CanonicalLogLine: + """Attach ``trace_id`` / ``span_id`` from a SpanContext to ``line``.""" + return line.add("trace_id", context.trace_id).add("span_id", + context.span_id) + + +class JSONLogFormatter(logging.Formatter): + """A ``logging.Formatter`` that emits one JSON object per record. + + Includes ``trace_id`` / ``span_id`` (and any non-standard ``extra=`` fields) + when present, for OTel log-trace correlation. + """ + + def format(self, record: logging.LogRecord) -> str: + payload: Dict[str, Any] = {"level": record.levelname, + "logger": record.name, + "message": record.getMessage()} + for key, value in vars(record).items(): + if key not in _STANDARD and not key.startswith("_"): + payload[key] = value + return json.dumps(payload, default=str) diff --git a/je_auto_control/utils/executor/action_executor.py b/je_auto_control/utils/executor/action_executor.py index 1160dd60..d355aaa1 100644 --- a/je_auto_control/utils/executor/action_executor.py +++ b/je_auto_control/utils/executor/action_executor.py @@ -3127,6 +3127,16 @@ def _baggage_parse(header: str) -> Dict[str, Any]: return {"items": parse_baggage(header).to_dict()} +def _canonical_log(fields: Any) -> Dict[str, Any]: + """Adapter: build a canonical log line from a fields dict.""" + import json + from je_auto_control.utils.canonical_log import CanonicalLogLine + if isinstance(fields, str): + fields = json.loads(fields) + line = CanonicalLogLine(fields) + return {"line": line.to_dict(), "json": line.render()} + + def _baggage_format(items: Any) -> Dict[str, Any]: """Adapter: serialise an items dict into a W3C baggage {header}.""" import json @@ -4378,6 +4388,7 @@ def __init__(self): "AC_trace_extract": _trace_extract, "AC_baggage_parse": _baggage_parse, "AC_baggage_format": _baggage_format, + "AC_canonical_log": _canonical_log, "AC_resolve_ref": _resolve_ref, "AC_resolve_refs": _resolve_refs, "AC_redact_config": _redact_config, diff --git a/je_auto_control/utils/mcp_server/tools/_factories.py b/je_auto_control/utils/mcp_server/tools/_factories.py index 37ccd3a1..0f10a604 100644 --- a/je_auto_control/utils/mcp_server/tools/_factories.py +++ b/je_auto_control/utils/mcp_server/tools/_factories.py @@ -3731,6 +3731,19 @@ def secret_ref_tools() -> List[MCPTool]: ] +def canonical_log_tools() -> List[MCPTool]: + return [ + MCPTool( + name="ac_canonical_log", + description=("Build a canonical (wide-event) log line from a " + "'fields' object. Returns {line, json}."), + input_schema=schema({"fields": {"type": "object"}}, ["fields"]), + handler=h.canonical_log, + annotations=READ_ONLY, + ), + ] + + def baggage_tools() -> List[MCPTool]: return [ MCPTool( @@ -5313,7 +5326,7 @@ def media_assert_tools() -> List[MCPTool]: search_index_tools, stats_tools, recurrence_tools, text_diff_tools, feature_flag_tools, provenance_tools, json_contract_tools, chaos_tools, slo_tools, percentiles_tools, bulkhead_tools, http_cassette_tools, - trace_context_tools, baggage_tools, secret_ref_tools, + trace_context_tools, baggage_tools, canonical_log_tools, secret_ref_tools, config_redaction_tools, data_profile_tools, http_problem_tools, dotenv_tools, sse_client_tools, layered_config_tools, data_drift_tools, diff --git a/je_auto_control/utils/mcp_server/tools/_handlers.py b/je_auto_control/utils/mcp_server/tools/_handlers.py index 3ac864b8..23eb3e38 100644 --- a/je_auto_control/utils/mcp_server/tools/_handlers.py +++ b/je_auto_control/utils/mcp_server/tools/_handlers.py @@ -1736,6 +1736,11 @@ def baggage_format(items): return _baggage_format(items) +def canonical_log(fields): + from je_auto_control.utils.executor.action_executor import _canonical_log + return _canonical_log(fields) + + def resolve_ref(ref): from je_auto_control.utils.executor.action_executor import _resolve_ref return _resolve_ref(ref) diff --git a/test/unit_test/headless/test_canonical_log_batch.py b/test/unit_test/headless/test_canonical_log_batch.py new file mode 100644 index 00000000..87e30203 --- /dev/null +++ b/test/unit_test/headless/test_canonical_log_batch.py @@ -0,0 +1,72 @@ +"""Headless tests for canonical log lines + JSON formatting. No Qt.""" +import json +import logging + +import pytest + +import je_auto_control as ac +from je_auto_control.utils.canonical_log import ( + CanonicalLogLine, JSONLogFormatter, bind_trace_context, +) + + +def test_add_update_and_render(): + line = CanonicalLogLine({"event": "run"}).add("ok", True).update({"n": 3}) + assert line.to_dict() == {"event": "run", "ok": True, "n": 3} + assert json.loads(line.render()) == {"event": "run", "ok": True, "n": 3} + + +def test_timer_uses_injected_clock(): + ticks = iter([10.0, 10.5]) + line = CanonicalLogLine(clock=lambda: next(ticks)) + with line.timer("step"): + pass + assert line.to_dict()["step_ms"] == pytest.approx(500.0) + + +def test_emit_to_sink(): + captured = [] + CanonicalLogLine({"a": 1}).emit(captured.append) + assert captured == [{"a": 1}] + + +def test_bind_trace_context(): + class _Ctx: + trace_id = "t" * 32 + span_id = "s" * 16 + line = bind_trace_context(CanonicalLogLine(), _Ctx()) + assert line.to_dict()["trace_id"] == "t" * 32 + assert line.to_dict()["span_id"] == "s" * 16 + + +def test_json_log_formatter_includes_extras(): + formatter = JSONLogFormatter() + record = logging.makeLogRecord( + {"name": "x", "levelname": "INFO", "msg": "hi", + "trace_id": "abc", "custom": 5}) + payload = json.loads(formatter.format(record)) + assert payload["message"] == "hi" and payload["level"] == "INFO" + assert payload["trace_id"] == "abc" and payload["custom"] == 5 + + +# --- wiring --------------------------------------------------------------- + +def test_executor_round_trip(): + rec = ac.execute_action([[ + "AC_canonical_log", {"fields": json.dumps({"event": "run", "ok": True})}]]) + out = next(v for v in rec.values() if isinstance(v, dict)) + assert out["line"] == {"event": "run", "ok": True} + assert json.loads(out["json"]) == {"event": "run", "ok": True} + + +def test_wiring(): + assert "AC_canonical_log" in ac.executor.known_commands() + from je_auto_control.utils.mcp_server.tools import build_default_tool_registry + assert "ac_canonical_log" in {t.name for t in build_default_tool_registry()} + from je_auto_control.gui.script_builder.command_schema import _build_specs + assert "AC_canonical_log" in {s.command for s in _build_specs()} + + +def test_facade_exports(): + for attr in ("CanonicalLogLine", "JSONLogFormatter", "bind_trace_context"): + assert hasattr(ac, attr) and attr in ac.__all__