From 82a348dae832b03e0882cbfabc1d3090d948f98d Mon Sep 17 00:00:00 2001 From: Nikhil Arora Date: Sat, 26 Sep 2026 17:37:12 +0530 Subject: [PATCH] Raise record contract to 2.0 This change bumps the minimum Python version to 3.10 and updates the log record contract to schema_version 2.0. It adds the shared JSON Schema and golden-record fixtures, a backward-compatible parse_record() loader for 1.x/2.x records, and the new top-level llm block plus reserved meta fields. The changelog, migration guide, formatter/parser updates, and New Relic transport handling are updated to keep the Python package aligned with the JS contract and catch schema drift in CI. --- .github/workflows/ci.yml | 2 +- CHANGELOG.md | 26 + CONTRIBUTING.md | 2 + MIGRATING.md | 82 ++ README.md | 44 +- logquill/__init__.py | 5 +- logquill/formatters/logfmt_formatter.py | 4 + logquill/formatters/text_formatter.py | 3 + logquill/parsing.py | 8 +- logquill/plugins/tamper_evident_plugin.py | 29 +- logquill/records.py | 114 +- logquill/serverless.py | 4 +- .../transports/cloud/new_relic_transport.py | 12 +- pyproject.toml | 19 +- schema/README.md | 49 + schema/golden_records.json | 981 ++++++++++++++++++ schema/record.schema.json | 157 +++ tests/test_contract.py | 223 ++++ tests/test_formatters.py | 24 + .../cloud/test_new_relic_transport.py | 22 + tests/test_transports/test_http_transport.py | 6 +- 21 files changed, 1765 insertions(+), 51 deletions(-) create mode 100644 MIGRATING.md create mode 100644 schema/README.md create mode 100644 schema/golden_records.json create mode 100644 schema/record.schema.json create mode 100644 tests/test_contract.py diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 67e3406..ac3cad9 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -11,7 +11,7 @@ jobs: strategy: fail-fast: false matrix: - python-version: ["3.8", "3.9", "3.10", "3.11", "3.12"] + python-version: ["3.10", "3.11", "3.12", "3.13", "3.14"] steps: - uses: actions/checkout@v7 diff --git a/CHANGELOG.md b/CHANGELOG.md index e754681..f221763 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,6 +4,32 @@ All notable changes to this project are documented in this file. ## Unreleased +- **Breaking: the record shape and the Python floor changed.** See + [MIGRATING.md](MIGRATING.md). + - logquill now requires **Python 3.10 or newer** and is tested on 3.10–3.14. + Python 3.8 and 3.9 are end-of-life; pip on those interpreters keeps + installing 1.x. + - Every record now carries `schema_version` (`"2.0"`). Nothing was renamed or + removed, so a reader only breaks if it insists on exactly the five 1.x + keys. `parse_record()` reads 1.x and 2.x records alike, labelling a 1.x + record `"1.0"`. + - New reserved fields, shared with `logquill` on npm: a top-level `llm` block + (`model`, `tokens_in`, `tokens_out`, `cost_usd`, `latency_ms`, + `finish_reason`) for LLM calls, plus `meta.retry_count`, `meta.state_diff` + and `meta.mcp.server`/`meta.mcp.tool`. The text and logfmt formatters show + the `llm` block. Nothing writes these on its own yet. + - `TamperEvidentPlugin` now covers `schema_version` and `llm` in the hash, so + editing either is caught; hash chains written by 1.x still verify. + - Fixed: the New Relic transport rebuilt each record from its five 1.x fields + and would have dropped `schema_version` and `llm`; it now copies the record. + - The record format now has a machine-readable definition, + `schema/record.schema.json` (JSON Schema 2020-12), and a shared file of + golden records, `schema/golden_records.json`. `tests/test_contract.py` + checks the schema, the golden records, the parser, and everything the + logger actually writes against each other, so drift between the Python and + JavaScript packages now fails a test instead of relying on a reviewer to + notice. + - Added the 1.0 features that hadn't shipped yet, plus hardening: - `logger.opt(lazy=True)` defers callable `meta` values until a record is really going to be emitted, so an expensive `DEBUG`/`TRACE` argument costs diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md index 235adf8..087b087 100644 --- a/CONTRIBUTING.md +++ b/CONTRIBUTING.md @@ -38,6 +38,8 @@ legitimately needs more memory, raise the budget in the same PR and say why. 4. `CHANGELOG.md` has an entry under `Unreleased` 5. Nothing in the cross-language contract table silently diverged from `logquill-js` (open a tracking issue there if it changed) + — if you change the record shape, change `schema/record.schema.json` and + `schema/golden_records.json` together (see `schema/README.md`) - **CI must be green** (`ruff check`, `mypy logquill`, `pytest`, `pytest benchmarks`) and **at least one review approval** is required before merge — enforced by branch protection on `main`. diff --git a/MIGRATING.md b/MIGRATING.md new file mode 100644 index 0000000..7a3d89b --- /dev/null +++ b/MIGRATING.md @@ -0,0 +1,82 @@ +# Migrating from logquill 1.x to 2.0 + +2.0 raises the minimum Python version and extends the record shape shared with +`logquill` on npm. Application code that only calls `logger.info(...)` and +friends needs no changes; what changes is what's on disk and on the wire, and +which Python you run. + +## 1. Python 3.10 or newer + +`logquill` 2.0 requires Python 3.10+ (it was 3.8+). It is tested on 3.10 +through 3.14. On an older interpreter, pip keeps installing the 1.x line. + +## 2. Every record carries `schema_version` + +Records now start with `"schema_version": "2.0"`: + +```json +{"schema_version":"2.0","timestamp":"2026-01-01T00:00:00.000Z","level":"INFO","logger":"app","message":"hello","meta":{}} +``` + +**If you read logs** — a parser, a dashboard, a SIEM rule — make sure it +tolerates one extra top-level key. Nothing was renamed or removed; a strict +"exactly these five keys" check is the only thing that breaks. + +**If you have existing 1.x logs**, they don't need converting. A record with no +`schema_version` is a 1.x record, and `parse_record` reads both: + +```python +import json + +from logquill import parse_record + +line = '{"timestamp":"2026-01-01T00:00:00.000Z","level":"INFO","logger":"app","message":"hi"}' + +record = parse_record(json.loads(line)) # a 1.x or 2.x line +assert record["schema_version"] == "1.0" # "2.0" for a 2.x record +assert record["meta"] == {} +``` + +It fills in `"1.0"` and an empty `meta` if either is missing, keeps every other +key, and raises `ValueError` — saying what to fix — for a record that isn't a +LogQuill record, or one written by a newer major version. + +**Hash-chained logs** (`TamperEvidentPlugin`) keep verifying: a chain written by +1.x verifies unchanged, and 2.x chains additionally cover `schema_version` and +`llm`, so editing either is caught. + +## 3. New optional fields + +These are defined now so both languages agree on them. Nothing emits them on its +own yet, and no record has them unless you add them. + +| Field | Where | Type | +|---|---|---| +| `llm.model`, `llm.finish_reason` | top level, `llm` block | string | +| `llm.tokens_in`, `llm.tokens_out` | `llm` block | integer ≥ 0 | +| `llm.cost_usd`, `llm.latency_ms` | `llm` block | number ≥ 0 | +| `meta.retry_count` | `meta` | integer ≥ 0 | +| `meta.state_diff` | `meta` | object | +| `meta.mcp.server`, `meta.mcp.tool` | `meta` | string | + +`llm` is its own block, not part of `meta`, because cost and latency +dashboards need stable names for it. A record that isn't an LLM call has no +`llm` key. + +## 4. The published schema + +`schema/record.schema.json` (JSON Schema 2020-12) defines a record precisely. +The top level is closed — `schema_version`, `timestamp`, `level`, `logger`, +`message`, `meta` and `llm` only — so put your own fields in `meta`, which stays +free-form. `schema/golden_records.json` holds example records that this package +and `logquill` on npm both test against. + +## 5. Small things + +- `LogRecord` gained `schema_version` (required) and `llm` (optional), and + `create_record()` sets them. If you build `LogRecord` values by hand in your + own transport or plugin, add `schema_version=SCHEMA_VERSION`, or build them + from `create_record()`. +- If a transport of yours rebuilds a record from its five 1.x fields, copy the + record instead (`{**record, "meta": new_meta}`) so `schema_version` and `llm` + aren't dropped. diff --git a/README.md b/README.md index f31a810..036cc95 100644 --- a/README.md +++ b/README.md @@ -3,7 +3,7 @@ [![CI](https://github.com/nikhilvdev/logquill-python/actions/workflows/ci.yml/badge.svg)](https://github.com/nikhilvdev/logquill-python/actions/workflows/ci.yml) [![Publish](https://github.com/nikhilvdev/logquill-python/actions/workflows/release.yml/badge.svg)](https://github.com/nikhilvdev/logquill-python/actions/workflows/release.yml) [![PyPI](https://img.shields.io/pypi/v/logquill.svg)](https://pypi.org/project/logquill/) -[![Python versions](https://img.shields.io/badge/python-3.8%2B-blue.svg)](pyproject.toml) +[![Python versions](https://img.shields.io/badge/python-3.10%2B-blue.svg)](pyproject.toml) [![License](https://img.shields.io/github/license/nikhilvdev/logquill-python)](LICENSE) [![GitHub tag](https://img.shields.io/github/v/tag/nikhilvdev/logquill-python)](https://github.com/nikhilvdev/logquill-python/tags) [![Downloads](https://static.pepy.tech/badge/logquill)](https://pepy.tech/project/logquill) @@ -37,6 +37,8 @@ for what's landed so far. ## Install +Requires Python 3.10 or newer (2.0 raised the floor from 3.8; see [MIGRATING.md](MIGRATING.md)). + ```bash pip install logquill ``` @@ -50,8 +52,8 @@ logger = Logger("app", level=Level.INFO) record = logger.info("user signed up", user_id=42, plan="pro") print(record) -# {'timestamp': '2026-08-27T18:04:12.345Z', 'level': 'INFO', 'logger': 'app', -# 'message': 'user signed up', 'meta': {'user_id': 42, 'plan': 'pro'}} +# {'schema_version': '2.0', 'timestamp': '2026-08-27T18:04:12.345Z', 'level': 'INFO', +# 'logger': 'app', 'message': 'user signed up', 'meta': {'user_id': 42, 'plan': 'pro'}} logger.debug("below threshold, dropped") # -> None, filtered by level logger.set_level("debug") @@ -59,7 +61,7 @@ logger.debug("now visible") # -> a record dict ``` Every log call returns the record dict (or `None` if filtered by level) — -`{"timestamp": ISO8601, "level": str, "logger": str, "message": str, "meta": dict}`, +`{"schema_version": "2.0", "timestamp": ISO8601, "level": str, "logger": str, "message": str, "meta": dict}`, the same shape shared with [`logquill` on npm](https://www.npmjs.com/package/logquill). Use `JSONFormatter` to serialize a record to the canonical JSON line: @@ -67,7 +69,39 @@ Use `JSONFormatter` to serialize a record to the canonical JSON line: from logquill import JSONFormatter print(JSONFormatter().format(record)) -# '{"timestamp":"2026-08-27T18:04:12.345Z","level":"INFO","logger":"app","message":"user signed up","meta":{"user_id":42,"plan":"pro"}}' +# '{"schema_version":"2.0","timestamp":"2026-08-27T18:04:12.345Z","level":"INFO","logger":"app","message":"user signed up","meta":{"user_id":42,"plan":"pro"}}' +``` + +### The record schema + +The record shape is defined precisely by [`schema/record.schema.json`](schema/record.schema.json) +(JSON Schema 2020-12), the same file `logquill` on npm is tested against, with +a shared set of [golden records](schema/golden_records.json) that both +packages' test suites run. Two things to know: + +- `schema_version` is on every record. `parse_record()` reads a record another + process wrote, and accepts both 2.x records and logquill 1.x ones (which have + no `schema_version` and come back labelled `"1.0"`). It raises `ValueError`, + saying what to fix, for anything that isn't a LogQuill record. +- An LLM call's cost and latency have their own top-level `llm` block + (`model`, `tokens_in`, `tokens_out`, `cost_usd`, `latency_ms`, + `finish_reason`), not free-form `meta`; `meta.retry_count`, + `meta.state_diff` and `meta.mcp.server`/`meta.mcp.tool` are reserved with + fixed types. + +```python +import json + +from logquill import JSONFormatter, Logger, parse_record + +logger = Logger("app") +line = JSONFormatter().format(logger.info("user signed up", user_id=42)) + +assert parse_record(json.loads(line))["schema_version"] == "2.0" + +# a line written by logquill 1.x +old = '{"timestamp":"2026-01-01T00:00:00.000Z","level":"INFO","logger":"app","message":"hi","meta":{}}' +assert parse_record(json.loads(old))["schema_version"] == "1.0" ``` ## Config diff --git a/logquill/__init__.py b/logquill/__init__.py index 6a32c77..6178484 100644 --- a/logquill/__init__.py +++ b/logquill/__init__.py @@ -22,7 +22,7 @@ from logquill.plugins.slack_alert_plugin import SlackAlertPlugin from logquill.plugins.tamper_evident_plugin import TamperEvidentPlugin from logquill.plugins.trace_context_plugin import TraceContextPlugin -from logquill.records import LogRecord +from logquill.records import SCHEMA_VERSION, LLMBlock, LogRecord, parse_record from logquill.serverless import with_azure_function, with_cloud_function, with_lambda from logquill.toggle import disable, enable, is_enabled from logquill.transports.batching_transport import BatchingTransport @@ -78,6 +78,7 @@ "KafkaTransport", "Level", "LogfmtFormatter", + "LLMBlock", "LogQuillAdapter", "LogQuillHandler", "LogRecord", @@ -96,6 +97,7 @@ "RedactPlugin", "RedisTransport", "RunPlugin", + "SCHEMA_VERSION", "SQLLogRow", "SQLiteTransport", "SQSTransport", @@ -120,6 +122,7 @@ "parse", "parse_level", "parse_logfmt", + "parse_record", "with_azure_function", "with_cloud_function", "with_lambda", diff --git a/logquill/formatters/logfmt_formatter.py b/logquill/formatters/logfmt_formatter.py index 9ae6ed4..4e977d4 100644 --- a/logquill/formatters/logfmt_formatter.py +++ b/logquill/formatters/logfmt_formatter.py @@ -81,6 +81,7 @@ class LogfmtFormatter: timestamp=2026-01-01T00:00:00.000Z level=INFO logger=app message="user signed up" user_id=42 + An LLM call's `llm` block follows as `llm.model=...`, `llm.tokens_in=...`. `meta` keys are emitted as top-level pairs after the four record fields; nested dicts flatten to dotted keys (`http.status=200`); lists are emitted as a JSON string. Values containing whitespace, `=`, quotes, or @@ -101,6 +102,9 @@ def format(self, record: LogRecord) -> str: f"logger={_quote(str(record['logger']))}", f"message={_quote(str(record['message']))}", ] + llm = record.get("llm") + if llm: + _flatten("llm", llm, 1, pairs) for meta_key, value in record["meta"].items(): key = _key(meta_key) if key in _RESERVED_KEYS: diff --git a/logquill/formatters/text_formatter.py b/logquill/formatters/text_formatter.py index 0746b31..b74507b 100644 --- a/logquill/formatters/text_formatter.py +++ b/logquill/formatters/text_formatter.py @@ -29,6 +29,9 @@ def format_text(record: Mapping[str, Any]) -> str: f"{record.get('timestamp', '?')} {str(record.get('level', '?')):<5} " f"{record.get('logger', '?')}: {record.get('message', '')}" ) + llm = record.get("llm") + if llm: + line += f" llm={_dump_meta(llm)}" if meta: line += f" {_dump_meta(meta)}" if stack is not None: diff --git a/logquill/parsing.py b/logquill/parsing.py index aeef772..2e62b38 100644 --- a/logquill/parsing.py +++ b/logquill/parsing.py @@ -9,16 +9,16 @@ #: Matches one entry written by `TextFormatter` (single-line entries; a #: traceback printed on the lines after an entry isn't part of the match). -#: Pass with `cast=TEXT_LOG_CASTS` to get `meta` back as a dict: +#: Pass with `cast=TEXT_LOG_CASTS` to get `meta` (and an LLM call's `llm`) back as dicts: #: #: parse("app.log", TEXT_LOG_PATTERN, cast=TEXT_LOG_CASTS) TEXT_LOG_PATTERN = ( r"^(?P\S+) (?P[A-Z]+)\s+(?P[^:\s]+): " - r"(?P.*?)(?: (?P\{.*\}))?$" + r"(?P.*?)(?: llm=(?P\{[^{}]*\}))?(?: (?P\{.*\}))?$" ) -#: `cast` mapping that decodes the `meta` group of `TEXT_LOG_PATTERN` from JSON. -TEXT_LOG_CASTS: dict[str, Callable[[str], Any]] = {"meta": json.loads} +#: `cast` mapping that decodes the `meta` and `llm` groups of `TEXT_LOG_PATTERN` from JSON. +TEXT_LOG_CASTS: dict[str, Callable[[str], Any]] = {"meta": json.loads, "llm": json.loads} def parse( diff --git a/logquill/plugins/tamper_evident_plugin.py b/logquill/plugins/tamper_evident_plugin.py index b08dcc7..bc4e391 100644 --- a/logquill/plugins/tamper_evident_plugin.py +++ b/logquill/plugins/tamper_evident_plugin.py @@ -6,7 +6,7 @@ from typing import Any from logquill.plugins.plugin import Plugin -from logquill.records import LogRecord +from logquill.records import LEGACY_SCHEMA_VERSION, LogRecord GENESIS_HASH = "0" * 64 @@ -68,15 +68,20 @@ def verify_chain( def _compute_hash(record: Mapping[str, Any], prev_hash: str) -> str: meta = record.get("meta", {}) - payload = json.dumps( - { - "timestamp": record.get("timestamp"), - "level": record.get("level"), - "logger": record.get("logger"), - "message": record.get("message"), - "meta": {k: v for k, v in meta.items() if k not in ("hash", "prev_hash")}, - }, - sort_keys=True, - default=str, - ) + content: dict[str, Any] = { + "timestamp": record.get("timestamp"), + "level": record.get("level"), + "logger": record.get("logger"), + "message": record.get("message"), + "meta": {k: v for k, v in meta.items() if k not in ("hash", "prev_hash")}, + } + # `schema_version` and `llm` are covered when present, so editing either is + # caught. A `schema_version` of "1.0" is what `parse_record` labels a record + # that had none, so it's left out: a chain written by logquill 1.x verifies + # the same before and after parsing. + if record.get("schema_version", LEGACY_SCHEMA_VERSION) != LEGACY_SCHEMA_VERSION: + content["schema_version"] = record["schema_version"] + if "llm" in record: + content["llm"] = record["llm"] + payload = json.dumps(content, sort_keys=True, default=str) return hashlib.sha256(f"{prev_hash}{payload}".encode()).hexdigest() diff --git a/logquill/records.py b/logquill/records.py index 227fa90..0c8bbfa 100644 --- a/logquill/records.py +++ b/logquill/records.py @@ -1,14 +1,39 @@ from __future__ import annotations +import re +from collections.abc import Mapping from datetime import datetime, timezone -from typing import Any, TypedDict +from typing import Any, TypedDict, cast from logquill.levels import Level +#: The record shape this version writes. Shared with logquill-js: a record +#: carries it as `schema_version` so a reader can tell which shape it has. +SCHEMA_VERSION = "2.0" -class LogRecord(TypedDict): - """The cross-language record shape shared with logquill-js.""" +#: What a record with no `schema_version` — anything written by logquill 1.x — +#: is taken to be. +LEGACY_SCHEMA_VERSION = "1.0" +_VERSION_PATTERN = re.compile(r"^(\d+)\.(\d+)$") +_SUPPORTED_MAJOR = int(SCHEMA_VERSION.split(".")[0]) + + +class LLMBlock(TypedDict, total=False): + """The LLM-call fields, first-class on a record rather than free-form + `meta` so cost and latency dashboards can rely on their names. Every key is + optional; a record that isn't an LLM call has no `llm` block at all.""" + + model: str + tokens_in: int + tokens_out: int + cost_usd: float + latency_ms: float + finish_reason: str + + +class _RequiredRecordFields(TypedDict): + schema_version: str timestamp: str level: str logger: str @@ -16,20 +41,93 @@ class LogRecord(TypedDict): meta: dict[str, Any] +class LogRecord(_RequiredRecordFields, total=False): + """The cross-language record shape shared with logquill-js. + + `llm` is present only on LLM-call records. See `schema/record.schema.json` + for the machine-readable definition both packages test against. + """ + + llm: LLMBlock + + def utc_timestamp() -> str: """ISO8601 UTC timestamp with millisecond precision, matching JS `Date.toISOString()`.""" now = datetime.now(timezone.utc) return f"{now.strftime('%Y-%m-%dT%H:%M:%S')}.{now.microsecond // 1000:03d}Z" -def create_record(*, level: Level, logger: str, message: str, meta: dict[str, Any]) -> LogRecord: - """Build a `LogRecord` with the current UTC timestamp and the level's - string name (not its numeric value, per the cross-language record - shape).""" - return LogRecord( +def create_record( + *, + level: Level, + logger: str, + message: str, + meta: dict[str, Any], + llm: LLMBlock | None = None, +) -> LogRecord: + """Build a `LogRecord` stamped with `SCHEMA_VERSION` and the current UTC + timestamp, and the level's string name (not its numeric value, per the + cross-language record shape). `llm` is included only when given.""" + record = LogRecord( + schema_version=SCHEMA_VERSION, timestamp=utc_timestamp(), level=level.name, logger=logger, message=message, meta=meta, ) + if llm is not None: + record["llm"] = llm + return record + + +def parse_record(raw: Mapping[str, Any]) -> LogRecord: + """Read a record another process wrote — a decoded JSON log line — into + the current shape, accepting both 2.x records and logquill 1.x ones. + + A record with no `schema_version` (everything 1.x wrote) comes back + labelled `"1.0"`, with everything else untouched: the 1.x fields mean the + same thing in 2.x, so nothing needs converting. A missing `meta` becomes + `{}`. Keys this version doesn't know are kept, so a record from a newer + minor version passes through without losing data. Returns a new dict; the + input isn't modified. + + Raises `ValueError` — saying what to fix — if a required field is missing + or has the wrong type, the level isn't one of `TRACE DEBUG INFO WARN ERROR + FATAL`, or the record's `schema_version` is a newer major version than this + logquill understands. + """ + if not isinstance(raw, Mapping): + raise ValueError(f"a log record must be a JSON object, got {type(raw).__name__}") + + record: dict[str, Any] = dict(raw) + version = record.setdefault("schema_version", LEGACY_SCHEMA_VERSION) + match = _VERSION_PATTERN.match(version) if isinstance(version, str) else None + if match is None: + raise ValueError( + f"schema_version must be a string like '2.0', got {version!r} — is this a " + "LogQuill record?" + ) + if int(match.group(1)) > _SUPPORTED_MAJOR: + raise ValueError( + f"this record has schema_version {version!r}, newer than the {SCHEMA_VERSION!r} " + "this logquill understands — upgrade logquill to read it" + ) + + for field in ("timestamp", "level", "logger", "message"): + if not isinstance(record.get(field), str): + raise ValueError(f"record field {field!r} must be a string, got {record.get(field)!r}") + if record["level"] not in Level.__members__: + raise ValueError( + f"record level {record['level']!r} isn't one of " + f"{', '.join(level.name for level in Level)} (upper case)" + ) + + meta = record.setdefault("meta", {}) + if not isinstance(meta, dict): + raise ValueError(f"record field 'meta' must be an object, got {type(meta).__name__}") + llm = record.get("llm") + if llm is not None and not isinstance(llm, dict): + raise ValueError(f"record field 'llm' must be an object, got {type(llm).__name__}") + + return cast(LogRecord, record) diff --git a/logquill/serverless.py b/logquill/serverless.py index e4eb1c1..3ac37d6 100644 --- a/logquill/serverless.py +++ b/logquill/serverless.py @@ -2,13 +2,13 @@ import functools import inspect -from typing import Any, Callable, Sequence, TypeVar, Union, cast +from typing import Any, Callable, Sequence, TypeVar, cast from logquill.logger import Logger F = TypeVar("F", bound=Callable[..., Any]) -LoggerOrLoggers = Union[Logger, Sequence[Logger]] +LoggerOrLoggers = Logger | Sequence[Logger] def _as_loggers(loggers: LoggerOrLoggers) -> tuple[Logger, ...]: diff --git a/logquill/transports/cloud/new_relic_transport.py b/logquill/transports/cloud/new_relic_transport.py index c1bae62..0a54df1 100644 --- a/logquill/transports/cloud/new_relic_transport.py +++ b/logquill/transports/cloud/new_relic_transport.py @@ -7,7 +7,7 @@ import urllib.error import urllib.request from email.utils import parsedate_to_datetime -from typing import Callable, Dict, Literal, Sequence, TypedDict +from typing import Callable, Literal, Sequence, TypedDict, cast from logquill.formatters import Formatter from logquill.records import LogRecord @@ -33,7 +33,7 @@ class NewRelicSenderResult(TypedDict): retry_after: str | None -NewRelicSender = Callable[[str, Dict[str, str], bytes], NewRelicSenderResult] +NewRelicSender = Callable[[str, dict[str, str], bytes], NewRelicSenderResult] def _urllib_sender(url: str, headers: dict[str, str], body: bytes) -> NewRelicSenderResult: @@ -50,13 +50,7 @@ def _urllib_sender(url: str, headers: dict[str, str], body: bytes) -> NewRelicSe def _without_event_type(record: LogRecord) -> LogRecord: meta = dict(record["meta"]) meta.pop("eventType", None) - return LogRecord( - timestamp=record["timestamp"], - level=record["level"], - logger=record["logger"], - message=record["message"], - meta=meta, - ) + return cast(LogRecord, {**record, "meta": meta}) def _resume_timestamp(retry_after: str | None, now: float) -> float: diff --git a/pyproject.toml b/pyproject.toml index 90ab9b3..cb594db 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -8,7 +8,7 @@ version = "1.0.0" description = "A structured, leveled logging framework with pluggable transports and a plugin pipeline." readme = "README.md" license = "MIT" -requires-python = ">=3.8" +requires-python = ">=3.10" authors = [{ name = "Nikhil Arora" }] keywords = [ "logging", @@ -26,11 +26,11 @@ classifiers = [ "License :: OSI Approved :: MIT License", "Operating System :: OS Independent", "Programming Language :: Python :: 3", - "Programming Language :: Python :: 3.8", - "Programming Language :: Python :: 3.9", "Programming Language :: Python :: 3.10", "Programming Language :: Python :: 3.11", "Programming Language :: Python :: 3.12", + "Programming Language :: Python :: 3.13", + "Programming Language :: Python :: 3.14", "Topic :: Software Development :: Libraries :: Python Modules", "Topic :: System :: Logging", "Typing :: Typed", @@ -64,12 +64,12 @@ dev = [ "pytest-asyncio>=0.24", "pytest-cov>=5.0", "hypothesis>=6.100", + "jsonschema>=4.18", "build>=1.2", "twine>=5.1", ] hooks = [ - # Separate from "dev": pre-commit dropped Python 3.8 support, but our - # CI matrix still tests 3.8, and pre-commit is only needed locally. + # Separate from "dev": only needed locally, not in CI. "pre-commit>=3.7", ] docs = [ @@ -98,8 +98,10 @@ include = [ "/logquill", "/tests", "/benchmarks", + "/schema", "/README.md", "/CHANGELOG.md", + "/MIGRATING.md", "/CODE_OF_CONDUCT.md", "/CONTRIBUTING.md", "/LICENSE", @@ -108,10 +110,15 @@ include = [ [tool.ruff] line-length = 100 -target-version = "py38" +target-version = "py310" [tool.ruff.lint] select = ["E", "F", "W", "I", "UP", "B", "C4", "SIM"] +# Importing `Callable`/`Sequence`/... from `typing` still works and is used +# throughout; moving them to `collections.abc` is churn with no behavior change. +# UP038 (`isinstance(x, (A, B))` -> `A | B`) is slower and has been dropped from +# newer ruff releases. +ignore = ["UP035", "UP038"] [tool.mypy] strict = true diff --git a/schema/README.md b/schema/README.md new file mode 100644 index 0000000..7ac7825 --- /dev/null +++ b/schema/README.md @@ -0,0 +1,49 @@ +# LogQuill record schema + +`record.schema.json` is the machine-readable definition of one log record +(JSON Schema draft 2020-12). `golden_records.json` is a set of example records +that every LogQuill implementation runs its tests against. Together they are +what keeps `logquill` (Python) and `logquill` (npm) writing the same shape. + +## Using the schema + +```python +import json + +import jsonschema + +from logquill import Logger + +schema = json.load(open("schema/record.schema.json")) +record = Logger("app").info("hello", user_id=42) + +jsonschema.validate(record, schema) # raises ValidationError if it doesn't conform +``` + +Run it from the repository root, or point `open` at wherever you keep the file. + +Field names in `meta` are snake_case (`run_id`, `span_id`, `duration_ms`) in +both languages. + +## What the golden records check + +`golden_records.json` has four groups. A LogQuill implementation's test suite +should load the file and assert: + +| Group | Assertion | +|---|---| +| `valid` | validates against `record.schema.json`, and equals itself after a JSON round trip | +| `invalid` | does **not** validate; `why` says which rule it breaks | +| `legacy` | the record parser turns `record` into exactly `parsed` (1.x records gain `schema_version: "1.0"`; a missing `meta` becomes `{}`) | +| `rejected` | the record parser refuses it | + +The Python tests are `tests/test_contract.py`. To add a rule, add a case to +the right group *and* to `record.schema.json` in one change, then update the +other implementations' copies before releasing. + +## Versions + +`schema_version` is `"."`. A new optional field is a minor +change; anything a reader of the previous version couldn't handle is a major +one. A reader accepts records with a newer minor version (keeping fields it +doesn't know) and refuses a newer major version. diff --git a/schema/golden_records.json b/schema/golden_records.json new file mode 100644 index 0000000..72055dc --- /dev/null +++ b/schema/golden_records.json @@ -0,0 +1,981 @@ +{ + "description": "Golden records shared by logquill-python and logquill-js. Both test suites load this file. `valid` records must validate against record.schema.json and survive a JSON round trip unchanged; `invalid` ones must not validate. `legacy` records must parse to exactly `parsed`; `rejected` ones must be refused by the record parser.", + "schema_version": "2.0", + "valid": [ + { + "name": "minimal record with empty meta", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": {} + } + }, + { + "name": "free-form meta, nested and mixed types", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "user signed up", + "meta": { + "user_id": 42, + "plan": "pro", + "ok": true, + "note": null, + "ratio": 0.5, + "tags": [ + "a", + "b" + ], + "http": { + "status": 201, + "headers": { + "x": "y" + } + } + } + } + }, + { + "name": "TRACE level", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "TRACE", + "logger": "app", + "message": "hello", + "meta": {} + } + }, + { + "name": "DEBUG level", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "DEBUG", + "logger": "app", + "message": "hello", + "meta": {} + } + }, + { + "name": "INFO level", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": {} + } + }, + { + "name": "WARN level", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "WARN", + "logger": "app", + "message": "hello", + "meta": {} + } + }, + { + "name": "ERROR level", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "ERROR", + "logger": "app", + "message": "hello", + "meta": {} + } + }, + { + "name": "FATAL level", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "FATAL", + "logger": "app", + "message": "hello", + "meta": {} + } + }, + { + "name": "error with a stack trace", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "ERROR", + "logger": "app.billing", + "message": "payment failed", + "meta": { + "stack": "Traceback (most recent call last):\n File \"x\", line 1\nValueError: nope\n", + "order_id": 7 + } + } + }, + { + "name": "agent span with nesting", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app.agent", + "message": "call_llm", + "meta": { + "kind": "span", + "run_id": "run-1", + "span_id": "00f067aa0ba902b7", + "parent_span_id": "b7ad6b7169203331", + "duration_ms": 812.5 + } + } + }, + { + "name": "agent step kinds", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "deciding", + "meta": { + "kind": "decision", + "run_id": "run-1" + } + } + }, + { + "name": "graph node and thread", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "node:plan", + "meta": { + "kind": "span", + "thread_id": "conv-9", + "node_name": "plan", + "run_id": "run-2", + "duration_ms": 3 + } + } + }, + { + "name": "cross-service trace id", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "handling request", + "meta": { + "trace_id": "4bf92f3577b34da6a3ce929d0e0e4736" + } + } + }, + { + "name": "full LLM call block", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app.agent", + "message": "chat", + "meta": { + "kind": "action", + "run_id": "run-1" + }, + "llm": { + "model": "example-model", + "tokens_in": 1200, + "tokens_out": 340, + "cost_usd": 0.0123, + "latency_ms": 2150.5, + "finish_reason": "stop" + } + } + }, + { + "name": "partial LLM call block", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "chat", + "meta": {}, + "llm": { + "model": "example-model" + } + } + }, + { + "name": "zero-valued LLM numbers", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "chat", + "meta": {}, + "llm": { + "tokens_in": 0, + "tokens_out": 0, + "cost_usd": 0, + "latency_ms": 0 + } + } + }, + { + "name": "retry count and state diff", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "call_tool", + "meta": { + "kind": "action", + "retry_count": 2, + "state_diff": { + "before": { + "items": 1 + }, + "after": { + "items": 2 + } + } + } + } + }, + { + "name": "MCP fields", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "tools/call", + "meta": { + "kind": "action", + "mcp": { + "server": "files", + "tool": "read_file" + } + } + } + }, + { + "name": "tamper-evident hash chain fields", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "audited", + "meta": { + "prev_hash": "0000000000000000000000000000000000000000000000000000000000000000", + "hash": "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa" + } + } + }, + { + "name": "non-ASCII text", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "héllo — 你好 🚀", + "meta": { + "名前": "值" + } + } + }, + { + "name": "timestamp with a numeric offset and no fraction", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T09:00:00+09:00", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": {} + } + } + ], + "invalid": [ + { + "name": "missing schema_version", + "why": "every 2.x record carries schema_version", + "record": { + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": {} + } + }, + { + "name": "a 1.x schema_version", + "why": "this schema describes 2.0; 1.x records are read with the legacy path", + "record": { + "schema_version": "1.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": {} + } + }, + { + "name": "schema_version is not a string", + "why": "a string like '2.0'", + "record": { + "schema_version": 2, + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": {} + } + }, + { + "name": "missing timestamp", + "why": "timestamp is required", + "record": { + "schema_version": "2.0", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": {} + } + }, + { + "name": "missing meta", + "why": "meta is required on a 2.x record", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello" + } + }, + { + "name": "lower-case level", + "why": "level names are upper case", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "info", + "logger": "app", + "message": "hello", + "meta": {} + } + }, + { + "name": "numeric level", + "why": "level is the name, not the weight", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": 20, + "logger": "app", + "message": "hello", + "meta": {} + } + }, + { + "name": "unknown level name", + "why": "not one of TRACE DEBUG INFO WARN ERROR FATAL", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "CRITICAL", + "logger": "app", + "message": "hello", + "meta": {} + } + }, + { + "name": "message is not a string", + "why": "message is a string", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": 42, + "meta": {} + } + }, + { + "name": "timestamp is not ISO 8601", + "why": "timestamp must be ISO 8601", + "record": { + "schema_version": "2.0", + "timestamp": "yesterday", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": {} + } + }, + { + "name": "timestamp is epoch milliseconds", + "why": "timestamp is a string", + "record": { + "schema_version": "2.0", + "timestamp": 1767225600000, + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": {} + } + }, + { + "name": "meta is an array", + "why": "meta is an object", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": [] + } + }, + { + "name": "unknown top-level key", + "why": "top level is closed; put extra fields in meta", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": {}, + "extra": 1 + } + }, + { + "name": "llm at the top level is not an object", + "why": "llm is an object", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": {}, + "llm": "gpt" + } + }, + { + "name": "llm with an unknown key", + "why": "llm is closed", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": {}, + "llm": { + "model": "m", + "temperature": 0.2 + } + } + }, + { + "name": "llm tokens_in is negative", + "why": "token counts are >= 0", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": {}, + "llm": { + "tokens_in": -1 + } + } + }, + { + "name": "llm tokens_out is a string", + "why": "token counts are integers", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": {}, + "llm": { + "tokens_out": "12" + } + } + }, + { + "name": "llm tokens_in is fractional", + "why": "token counts are integers", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": {}, + "llm": { + "tokens_in": 1.5 + } + } + }, + { + "name": "llm cost_usd is a string", + "why": "cost_usd is a number", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": {}, + "llm": { + "cost_usd": "0.01" + } + } + }, + { + "name": "llm latency_ms is negative", + "why": "latency is >= 0", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": {}, + "llm": { + "latency_ms": -5 + } + } + }, + { + "name": "retry_count is a string", + "why": "retry_count is an integer", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": { + "retry_count": "2" + } + } + }, + { + "name": "retry_count is negative", + "why": "retry_count is >= 0", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": { + "retry_count": -1 + } + } + }, + { + "name": "retry_count is fractional", + "why": "retry_count is an integer", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": { + "retry_count": 1.5 + } + } + }, + { + "name": "state_diff is a string", + "why": "state_diff is an object", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": { + "state_diff": "changed" + } + } + }, + { + "name": "mcp is a string", + "why": "mcp is an object", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": { + "mcp": "files" + } + } + }, + { + "name": "mcp.server is a number", + "why": "mcp.server is a string", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": { + "mcp": { + "server": 1 + } + } + } + }, + { + "name": "mcp.tool is a number", + "why": "mcp.tool is a string", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": { + "mcp": { + "tool": 1 + } + } + } + }, + { + "name": "duration_ms is a string", + "why": "duration_ms is a number", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": { + "duration_ms": "12" + } + } + }, + { + "name": "duration_ms is negative", + "why": "duration_ms is >= 0", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": { + "duration_ms": -1 + } + } + }, + { + "name": "span_id is a number", + "why": "ids are strings", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": { + "span_id": 7 + } + } + }, + { + "name": "hash is not 64 hex characters", + "why": "hash is a SHA-256 hex digest", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": { + "hash": "abc" + } + } + } + ], + "legacy": [ + { + "name": "1.x record", + "parsed": { + "schema_version": "1.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": { + "user_id": 42 + } + }, + "record": { + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": { + "user_id": 42 + } + } + }, + { + "name": "1.x agent span", + "parsed": { + "schema_version": "1.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app.agent", + "message": "call_llm", + "meta": { + "kind": "span", + "run_id": "run-1", + "span_id": "00f067aa0ba902b7", + "duration_ms": 12.5 + } + }, + "record": { + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app.agent", + "message": "call_llm", + "meta": { + "kind": "span", + "run_id": "run-1", + "span_id": "00f067aa0ba902b7", + "duration_ms": 12.5 + } + } + }, + { + "name": "record with no meta at all", + "parsed": { + "schema_version": "1.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "WARN", + "logger": "app", + "message": "no meta at all", + "meta": {} + }, + "record": { + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "WARN", + "logger": "app", + "message": "no meta at all" + } + }, + { + "name": "2.x record passes through unchanged", + "parsed": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hi", + "meta": {}, + "llm": { + "model": "m" + } + }, + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hi", + "meta": {}, + "llm": { + "model": "m" + } + } + }, + { + "name": "unknown extra keys are kept", + "parsed": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": {}, + "future_field": 1 + }, + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": {}, + "future_field": 1 + } + } + ], + "rejected": [ + { + "name": "not an object", + "why": "a record is a JSON object", + "record": [ + "a", + "list" + ] + }, + { + "name": "missing message", + "why": "message is required", + "record": { + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "meta": { + "user_id": 42 + } + } + }, + { + "name": "missing logger", + "why": "logger is required", + "record": { + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "message": "hello", + "meta": { + "user_id": 42 + } + } + }, + { + "name": "level is not a level name", + "why": "level names are upper case", + "record": { + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "info", + "logger": "app", + "message": "hello", + "meta": { + "user_id": 42 + } + } + }, + { + "name": "level is numeric", + "why": "level is the name", + "record": { + "timestamp": "2026-01-01T00:00:00.000Z", + "level": 20, + "logger": "app", + "message": "hello", + "meta": { + "user_id": 42 + } + } + }, + { + "name": "timestamp is a number", + "why": "timestamp is a string", + "record": { + "timestamp": 1767225600000, + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": { + "user_id": 42 + } + } + }, + { + "name": "meta is a string", + "why": "meta is an object", + "record": { + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": "x" + } + }, + { + "name": "llm is a string", + "why": "llm is an object", + "record": { + "schema_version": "2.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": {}, + "llm": "gpt" + } + }, + { + "name": "schema_version from a newer major version", + "why": "written by a newer logquill; upgrade to read it", + "record": { + "schema_version": "3.0", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": {} + } + }, + { + "name": "schema_version is not a version string", + "why": "a string like '2.0'", + "record": { + "schema_version": "two", + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": {} + } + }, + { + "name": "schema_version is a number", + "why": "a string like '2.0'", + "record": { + "schema_version": 2, + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "app", + "message": "hello", + "meta": {} + } + } + ] +} diff --git a/schema/record.schema.json b/schema/record.schema.json new file mode 100644 index 0000000..1877c0a --- /dev/null +++ b/schema/record.schema.json @@ -0,0 +1,157 @@ +{ + "$schema": "https://json-schema.org/draft/2020-12/schema", + "$id": "https://raw.githubusercontent.com/nikhilvdev/logquill-python/main/schema/record.schema.json", + "title": "LogQuill record", + "description": "One log record, as written by logquill (Python) and logquill-js. `meta` is free-form except for the named fields below, which both packages agree on. Records written by logquill 1.x have no `schema_version` and are not valid against this schema; read them with parse_record (Python), which labels them '1.0'.", + "type": "object", + "required": [ + "schema_version", + "timestamp", + "level", + "logger", + "message", + "meta" + ], + "additionalProperties": false, + "properties": { + "schema_version": { + "const": "2.0", + "description": "The record shape this schema describes." + }, + "timestamp": { + "type": "string", + "format": "date-time", + "pattern": "^\\d{4}-\\d{2}-\\d{2}T\\d{2}:\\d{2}:\\d{2}(\\.\\d+)?(Z|[+-]\\d{2}:\\d{2})$", + "description": "ISO 8601, e.g. 2026-01-01T00:00:00.000Z." + }, + "level": { + "enum": [ + "TRACE", + "DEBUG", + "INFO", + "WARN", + "ERROR", + "FATAL" + ] + }, + "logger": { + "type": "string", + "description": "Dotted logger name." + }, + "message": { + "type": "string" + }, + "meta": { + "$ref": "#/$defs/meta" + }, + "llm": { + "$ref": "#/$defs/llm" + } + }, + "$defs": { + "meta": { + "type": "object", + "description": "Free-form key/values. The keys named here have fixed meanings and types.", + "additionalProperties": true, + "properties": { + "kind": { + "type": "string", + "description": "thought | action | observation | decision; free-form otherwise (e.g. span, checkpoint)." + }, + "run_id": { + "type": "string", + "description": "Groups one agent run." + }, + "span_id": { + "type": "string" + }, + "parent_span_id": { + "type": "string" + }, + "trace_id": { + "type": "string", + "description": "Follows a request across services; distinct from run_id." + }, + "thread_id": { + "type": "string", + "description": "A resumable conversation spanning several run_ids." + }, + "node_name": { + "type": "string", + "description": "The graph node that produced the record." + }, + "duration_ms": { + "type": "number", + "minimum": 0, + "description": "Set on span close." + }, + "retry_count": { + "type": "integer", + "minimum": 0, + "description": "How many times this tool call has been retried." + }, + "state_diff": { + "type": "object", + "description": "State captured before and after a span." + }, + "mcp": { + "$ref": "#/$defs/mcp" + }, + "stack": { + "type": "string", + "description": "Formatted traceback." + }, + "hash": { + "type": "string", + "pattern": "^[0-9a-f]{64}$" + }, + "prev_hash": { + "type": "string", + "pattern": "^[0-9a-f]{64}$" + } + } + }, + "mcp": { + "type": "object", + "description": "Model Context Protocol fields.", + "additionalProperties": true, + "properties": { + "server": { + "type": "string" + }, + "tool": { + "type": "string" + } + } + }, + "llm": { + "type": "object", + "description": "An LLM call. Present only on LLM-call records; every field is optional.", + "additionalProperties": false, + "properties": { + "model": { + "type": "string" + }, + "tokens_in": { + "type": "integer", + "minimum": 0 + }, + "tokens_out": { + "type": "integer", + "minimum": 0 + }, + "cost_usd": { + "type": "number", + "minimum": 0 + }, + "latency_ms": { + "type": "number", + "minimum": 0 + }, + "finish_reason": { + "type": "string" + } + } + } + } +} diff --git a/tests/test_contract.py b/tests/test_contract.py new file mode 100644 index 0000000..0635478 --- /dev/null +++ b/tests/test_contract.py @@ -0,0 +1,223 @@ +"""The cross-language record contract: `schema/record.schema.json` and the +golden records in `schema/golden_records.json`, which logquill-js tests against +too. These tests are what keep this package's output, its parser and the +published schema saying the same thing.""" + +from __future__ import annotations + +import json +from pathlib import Path +from typing import Any + +import pytest + +from logquill import ( + JSONFormatter, + Level, + Logger, + LogQuillHandler, + RunPlugin, + TamperEvidentPlugin, + TraceContextPlugin, + parse_record, +) +from logquill.records import LEGACY_SCHEMA_VERSION, SCHEMA_VERSION, create_record +from logquill.transports.transport import CollectingTransport + +SCHEMA_DIR = Path(__file__).resolve().parent.parent / "schema" +SCHEMA = json.loads((SCHEMA_DIR / "record.schema.json").read_text(encoding="utf-8")) +GOLDEN = json.loads((SCHEMA_DIR / "golden_records.json").read_text(encoding="utf-8")) + + +def _entries(group: str) -> list[Any]: + return [pytest.param(entry, id=entry["name"]) for entry in GOLDEN[group]] + + +@pytest.fixture(scope="module") +def validator() -> Any: + jsonschema = pytest.importorskip("jsonschema") + return jsonschema.Draft202012Validator(SCHEMA, format_checker=jsonschema.FormatChecker()) + + +def test_the_schema_is_itself_a_valid_json_schema() -> None: + jsonschema = pytest.importorskip("jsonschema") + + jsonschema.Draft202012Validator.check_schema(SCHEMA) + + +def test_schema_and_fixtures_name_the_version_this_package_writes() -> None: + assert SCHEMA["properties"]["schema_version"]["const"] == SCHEMA_VERSION + assert GOLDEN["schema_version"] == SCHEMA_VERSION + + +@pytest.mark.parametrize("entry", _entries("valid")) +def test_valid_golden_records_validate_and_round_trip( + entry: dict[str, Any], validator: Any +) -> None: + record = entry["record"] + + validator.validate(record) + + assert json.loads(json.dumps(record)) == record + assert parse_record(record) == record + + +@pytest.mark.parametrize("entry", _entries("invalid")) +def test_invalid_golden_records_are_rejected_by_the_schema( + entry: dict[str, Any], validator: Any +) -> None: + assert not validator.is_valid(entry["record"]), entry["why"] + + +@pytest.mark.parametrize("entry", _entries("legacy")) +def test_legacy_golden_records_parse_to_the_expected_shape(entry: dict[str, Any]) -> None: + assert parse_record(entry["record"]) == entry["parsed"] + + +@pytest.mark.parametrize("entry", _entries("rejected")) +def test_rejected_golden_records_are_refused_by_the_parser(entry: dict[str, Any]) -> None: + with pytest.raises(ValueError): + parse_record(entry["record"]) + + +def test_a_1x_record_is_labelled_1_0_and_the_input_is_left_alone() -> None: + raw = {"timestamp": "2026-01-01T00:00:00.000Z", "level": "INFO", "logger": "a", "message": "m"} + + parsed = parse_record(raw) + + assert parsed["schema_version"] == LEGACY_SCHEMA_VERSION + assert parsed["meta"] == {} + assert "schema_version" not in raw and "meta" not in raw + + +def test_parse_errors_say_what_to_do() -> None: + with pytest.raises(ValueError, match="upgrade logquill"): + parse_record({"schema_version": "3.0"}) + with pytest.raises(ValueError, match="upper case"): + parse_record({"timestamp": "t", "level": "info", "logger": "a", "message": "m", "meta": {}}) + with pytest.raises(ValueError, match="'message' must be a string"): + parse_record({"timestamp": "t", "level": "INFO", "logger": "a", "meta": {}}) + + +# --- what this package actually writes must satisfy the schema --------------- + + +def _written(logger: Logger, sink: CollectingTransport) -> list[dict[str, Any]]: + return [json.loads(JSONFormatter().format(record)) for record in sink.records] + + +def test_every_record_the_logger_writes_carries_the_schema_version() -> None: + record = Logger("app").info("hello") + + assert record is not None + assert record["schema_version"] == SCHEMA_VERSION + + +def test_records_from_a_full_pipeline_validate_against_the_schema(validator: Any) -> None: + sink = CollectingTransport() + logger = Logger( + "app.agent", + level="TRACE", + transports=[sink], + plugins=[RunPlugin(), TraceContextPlugin(), TamperEvidentPlugin()], + ) + + logger.trace("t") + logger.info("plain", user_id=42, nested={"a": [1, 2, {"b": None}]}) + logger.thought("hmm") + logger.action("call", retry_count=1) + logger.observation("got it") + logger.decision("done") + with logger.span("outer"), logger.span("inner"): + logger.info("inside") + try: + _ = 1 / 0 + except ZeroDivisionError as exc: + logger.error("failed", exc_info=exc) + logger.opt(depth=0).warn("with caller") + logger.fatal("fatal") + + written = _written(logger, sink) + assert len(written) >= 12 + for record in written: + validator.validate(record) + assert parse_record(record) == record + + +def test_records_from_the_stdlib_bridge_validate(validator: Any) -> None: + import logging + + sink = CollectingTransport() + logger = Logger("bridge", transports=[sink]) + stdlib = logging.getLogger("contract-bridge-test") + handler = LogQuillHandler(logger) + stdlib.addHandler(handler) + stdlib.propagate = False + try: + stdlib.warning("retrying", extra={"attempt": 2}) + finally: + stdlib.removeHandler(handler) + + for record in _written(logger, sink): + validator.validate(record) + + +def test_an_llm_record_from_create_record_validates(validator: Any) -> None: + record = create_record( + level=Level.INFO, + logger="app", + message="chat", + meta={"kind": "action"}, + llm={"model": "m", "tokens_in": 10, "tokens_out": 5, "cost_usd": 0.5, "latency_ms": 9.5}, + ) + + validator.validate(json.loads(JSONFormatter().format(record))) + + +def test_create_record_omits_llm_unless_given() -> None: + record = create_record(level=Level.INFO, logger="a", message="m", meta={}) + + assert "llm" not in record + + +# --- integrity: the hash chain covers the new fields, and still verifies 1.x -- + + +def test_the_hash_chain_detects_edits_to_schema_version_and_the_llm_block() -> None: + plugin = TamperEvidentPlugin() + records = [] + for cost in (0.1, 0.2): + record = create_record( + level=Level.INFO, logger="a", message="chat", meta={}, llm={"cost_usd": cost} + ) + plugin.before_log(record) + records.append(record) + assert TamperEvidentPlugin.verify_chain(records) is True + + records[1]["llm"]["cost_usd"] = 0.0 # type: ignore[typeddict-item] + assert TamperEvidentPlugin.verify_chain(records) is False + records[1]["llm"]["cost_usd"] = 0.2 # type: ignore[typeddict-item] + records[1]["schema_version"] = "9.9" + assert TamperEvidentPlugin.verify_chain(records) is False + + +def test_a_hash_chain_written_by_1x_still_verifies() -> None: + plugin = TamperEvidentPlugin() + chain = [] + for i in range(3): + # a 1.x record: no schema_version + record: Any = { + "timestamp": "2026-01-01T00:00:00.000Z", + "level": "INFO", + "logger": "a", + "message": f"step {i}", + "meta": {}, + } + plugin.before_log(record) + chain.append(record) + + assert TamperEvidentPlugin.verify_chain(chain) is True + assert TamperEvidentPlugin.verify_chain([parse_record(r) for r in chain]) is True + + chain[1]["message"] = "edited" + assert TamperEvidentPlugin.verify_chain(chain) is False diff --git a/tests/test_formatters.py b/tests/test_formatters.py index 540b58b..743f61b 100644 --- a/tests/test_formatters.py +++ b/tests/test_formatters.py @@ -154,3 +154,27 @@ def test_logfmt_round_trips_through_parse_logfmt() -> None: assert fields["n"] == "7" assert fields["empty"] == "" assert fields["message"] == "user signed up" + + +def test_text_and_logfmt_show_an_llm_block() -> None: + record = _record("chat", kind="action") + record["llm"] = {"model": "m1", "tokens_in": 5, "cost_usd": 0.25} + + assert 'llm={"model":"m1","tokens_in":5,"cost_usd":0.25}' in TextFormatter().format(record) + fields = parse_logfmt(LogfmtFormatter().format(record)) + assert fields["llm.model"] == "m1" + assert fields["llm.tokens_in"] == "5" + assert fields["kind"] == "action" + + +def test_the_text_pattern_reads_an_llm_block_back() -> None: + from logquill import TEXT_LOG_CASTS, TEXT_LOG_PATTERN, parse + + record = _record("chat", kind="action") + record["llm"] = {"model": "m1", "tokens_in": 5} + + (entry,) = parse([TextFormatter().format(record)], TEXT_LOG_PATTERN, cast=TEXT_LOG_CASTS) + + assert entry["message"] == "chat" + assert entry["llm"] == {"model": "m1", "tokens_in": 5} + assert entry["meta"] == {"kind": "action"} diff --git a/tests/test_transports/cloud/test_new_relic_transport.py b/tests/test_transports/cloud/test_new_relic_transport.py index ccb9744..f27b80c 100644 --- a/tests/test_transports/cloud/test_new_relic_transport.py +++ b/tests/test_transports/cloud/test_new_relic_transport.py @@ -48,6 +48,28 @@ def test_region_url_gzip_body_and_headers() -> None: assert records[0]["meta"]["extra"] == "kept" +def test_stripping_event_type_keeps_the_schema_version_and_llm_block() -> None: + from logquill import Level + from logquill.records import create_record + + sender = FakeSender() + transport = NewRelicTransport(license_key="lk-1", sender=sender, max_records=1) + record = create_record( + level=Level.INFO, + logger="app.test", + message="chat", + meta={"eventType": "Custom"}, + llm={"model": "m", "tokens_in": 3}, + ) + + transport.write("", record) + + (sent,) = json.loads(gzip.decompress(sender.calls[0][2])) + assert sent["schema_version"] == "2.0" + assert sent["llm"] == {"model": "m", "tokens_in": 3} + assert "eventType" not in sent["meta"] + + def test_429_pauses_sends_and_drops_batches_during_the_window() -> None: sender = FakeSender() sender.results = [{"ok": False, "status": 429, "retry_after": "60"}] diff --git a/tests/test_transports/test_http_transport.py b/tests/test_transports/test_http_transport.py index 788982a..edcda65 100644 --- a/tests/test_transports/test_http_transport.py +++ b/tests/test_transports/test_http_transport.py @@ -1,6 +1,6 @@ import logging import sys -from typing import List, Sequence, Tuple +from typing import Sequence import pytest @@ -12,7 +12,7 @@ class FakeSender: """Fake sink standing in for the network call, so tests never hit the wire.""" def __init__(self) -> None: - self.calls: List[Tuple[str, Sequence[str]]] = [] + self.calls: list[tuple[str, Sequence[str]]] = [] def __call__(self, url: str, batch: Sequence[str]) -> None: self.calls.append((url, list(batch))) @@ -67,7 +67,7 @@ def test_flushes_early_when_the_buffered_bytes_reach_max_bytes() -> None: def test_a_failing_sender_is_logged_not_raised_and_later_records_still_flow( caplog: pytest.LogCaptureFixture, ) -> None: - calls: List[int] = [] + calls: list[int] = [] def flaky(url: str, batch: Sequence[str]) -> None: calls.append(len(batch))