Skip to content

chore(octopus): log repeated GraphQL responses and slot lists briefly instead of in full - #5428

Open
chalfontchubby wants to merge 2 commits into
mainfrom
chore/log-reduction
Open

chalfontchubby wants to merge 2 commits into
mainfrom
chore/log-reduction

Conversation

@chalfontchubby

Copy link
Copy Markdown
Collaborator

Opened by Claude on Rik's behalf.

Summary

On a live system with an Octopus account, about 40% of predbat.log was the same text logged again and again. The biggest single item was the saving sessions GraphQL response, about 22 KB, logged in full on every poll and then a second time as "Fetched saving sessions data". This logs a repeat as one short line instead, without losing anything.

  • GraphQL requests and responses: a request or response already logged in full within the last hour is logged as one line saying when it was logged in full (and, for a response, its size). It is logged in full again at least hourly, so the full text is never only in a rotated-out log. An error response is always logged in full, with the request that caused it, including on the 401/403, WAF-block and timeout paths. The duplicate "Fetched saving sessions data" line is dropped.
  • Intelligent slot list: about 16 lines every plan, now logged in full only when it changes (or hourly), otherwise as one line. An empty list is not logged, as before.
  • Weekend Happy Hour: "Not offering ... it cannot be joined" is logged hourly per event, not on every poll.

The decision is one small class, RepeatLogGate (utils.py). For each key it keeps a hash of each text logged in full, not the text itself, so:

  • several texts can alternate under one key without forcing each other out: one request context serving several Intelligent devices, or tariff comparison runs whose slot prices differ;
  • entries older than the interval are dropped, so memory stays bounded;
  • expiry runs on a monotonic clock, so a clock change cannot stretch it, and the time shown is local wall-clock time, matching the log's own timestamps.

The JWT stays redacted on every line.

Not changed

  • write_and_poll ... No write needed, which shows the control is being checked.
  • The per-run "Inverter does not support reserve" note, about 0.5% of the log.
  • The short repeat lines name the request context, not the device. With two Intelligent devices, the brief lines for each look alike. The full lines still differ.

Changes

  • apps/predbat/utils.py: RepeatLogGate.
  • apps/predbat/const.py: REPEAT_FULL_LOG_SECONDS (3600).
  • apps/predbat/octopus.py: the GraphQL logging, the slot list and the Happy Hour line go through the gate.
  • apps/predbat/predbat.py: the slot-list gate in reset().
  • docs/components.md: the get_log example line no longer quotes the dropped line.
  • Tests: test_octopus_logging (repeat, change, hourly re-log, two queries per context, errors, the gate itself, token redaction), test_rate_add_io_slots (slot list), test_octopus_saving_event_type (Happy Hour, including an event with no code), and test_web_mcp (fixture line).

Test plan

  • Full suite and pre-commit pass on each commit.
  • Measure the log size on a live system after deploying.

🤖 Generated with Claude Code

chalfontchubby and others added 2 commits October 7, 2026 13:36
…ead of in full

The Octopus GraphQL logging was about 30% of a typical log: every request logged its fixed query text and every
response its full body, poll after poll, and the saving sessions response (about 22 KB) was then logged a
second time as "Fetched saving sessions data". Now a request or response already logged in full within the hour
is logged as one line saying when it was last logged in full, and is logged in full again at least hourly so the
full text is never only in a rotated-out log file. The duplicate saving sessions line is dropped.

The decision is a new RepeatLogGate (utils.py): it keeps only a hash of each text per key, so several queries
sharing one request context (one per Intelligent device) each keep their own entry, and drops entries older than
the interval so its memory stays bounded. An error response is always logged in full, with the request that
caused it. The JWT stays redacted on every line.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…nd each Happy Hour skip hourly

The slot list (about 16 lines) was logged on every plan though it rarely changes; it now goes through the same
RepeatLogGate, logged in full when it changes and at least hourly, and as one line saying when it was last
logged in full otherwise. Tariff comparison runs, whose slot prices differ, keep their own entries rather than
forcing the live list to be logged again. An empty list is not logged, as before. The "Not offering Weekend Happy
Hour" line is logged once an hour per event code rather than on every poll of the event list.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@chalfontchubby chalfontchubby added the enhancement New feature or request label Oct 7, 2026

This branch has not been deployed

No deployments
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

enhancement New feature or request

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant