perf: JSON log formatter tests serializability of every field on every log call #96

Closed
opened 2026-03-20 13:18:08 +00:00 by cal · 1 comment
Owner

Problem

utils/logging.py JSONFormatter.format() (lines 93–101) iterates all record.__dict__ keys (20–30 per record) and calls json.dumps(value) on each one to test if it's JSON-serializable. This full serialization pass is done just to test — the result is discarded. It runs on every single log call across the entire bot.

for key, value in record.__dict__.items():
    try:
        json.dumps(value)  # Full serialization just to test
        extra_fields[key] = value
    except (TypeError, ValueError):
        extra_fields[key] = str(value)

With @logged_command logging start + end for every command, cache decorator debug logs, and background task loops, this adds up significantly.

Fix

Replace serialization test with a type check fast path:

SERIALIZABLE_TYPES = (str, int, float, bool, type(None))

for key, value in record.__dict__.items():
    if isinstance(value, SERIALIZABLE_TYPES):
        extra_fields[key] = value
    elif isinstance(value, (list, dict)):
        extra_fields[key] = value  # Trust stdlib types
    else:
        extra_fields[key] = str(value)

Or use a custom default function in the final json.dumps() call to handle non-serializable types during actual serialization.

Impact

MEDIUM — This is the highest-frequency overhead in the bot. Every log line pays this cost.

## Problem `utils/logging.py` `JSONFormatter.format()` (lines 93–101) iterates all `record.__dict__` keys (20–30 per record) and calls `json.dumps(value)` on each one to test if it's JSON-serializable. This full serialization pass is done just to test — the result is discarded. It runs on **every single log call** across the entire bot. ```python for key, value in record.__dict__.items(): try: json.dumps(value) # Full serialization just to test extra_fields[key] = value except (TypeError, ValueError): extra_fields[key] = str(value) ``` With `@logged_command` logging start + end for every command, cache decorator debug logs, and background task loops, this adds up significantly. ## Fix Replace serialization test with a type check fast path: ```python SERIALIZABLE_TYPES = (str, int, float, bool, type(None)) for key, value in record.__dict__.items(): if isinstance(value, SERIALIZABLE_TYPES): extra_fields[key] = value elif isinstance(value, (list, dict)): extra_fields[key] = value # Trust stdlib types else: extra_fields[key] = str(value) ``` Or use a custom `default` function in the final `json.dumps()` call to handle non-serializable types during actual serialization. ## Impact **MEDIUM** — This is the highest-frequency overhead in the bot. Every log line pays this cost.
cal added the
ai-working
label 2026-03-20 13:18:41 +00:00
cal removed the
ai-working
label 2026-03-20 13:21:33 +00:00
Claude added the
ai-working
status/in-progress
labels 2026-03-20 17:31:50 +00:00
Claude removed the
status/in-progress
label 2026-03-20 17:32:55 +00:00
Collaborator

PR #109 opened: #109

Replaced the json.dumps(value) serialization probe with an isinstance() type-check fast path. The constant _SERIALIZABLE_TYPES is defined at module level to avoid tuple recreation on every log call. 935 tests pass.

PR #109 opened: https://git.manticorum.com/cal/major-domo-v2/pulls/109 Replaced the `json.dumps(value)` serialization probe with an `isinstance()` type-check fast path. The constant `_SERIALIZABLE_TYPES` is defined at module level to avoid tuple recreation on every log call. 935 tests pass.
Claude added
status/pr-open
ai-pr-opened
and removed
ai-working
labels 2026-03-20 17:33:04 +00:00
cal closed this issue 2026-03-20 17:38:59 +00:00
Sign in to join this conversation.
No Milestone
No project
No Assignees
2 Participants
Notifications
Due Date
The due date is invalid or out of range. Please use the format 'yyyy-mm-dd'.

No due date set.

Dependencies

No dependencies set.

Reference: cal/major-domo-v2#96
No description provided.