Skip to content

log.message is stored as text, forcing an 85 MB jsonb parse on every financial-log read #4509

Description

@TaprootFreak

log.message holds JSON but is declared text, so every read of the financial log re-parses the documents from scratch. The financial overview screen refreshes 60 times per hour, which turns this into a recurring CPU cost on the single Node process.

Measured (production, standard 3-day window)

rows in window                     2,066
message, compressed (on disk)      20 MB
message, uncompressed              85 MB     ← what has to be parsed
average per document               42 kB

Every call that touches message::jsonb parses those 85 MB. At the overview screen's refresh rate that is roughly 5 GB of JSON parsing per hour, for data that was serialized by this same application one minute earlier.

The cost is CPU-bound, not I/O: sampling pg_stat_activity during these queries shows wait_event: RUN consistently.

Why the existing work does not cover it

Both are the right changes; neither removes the parse, because the column type is the cause.

Options (ranked by effort)

  1. Change the column to jsonb. Parsing then happens once, at write time. Reads become direct field access, and -> on a jsonb column can use expression indexes. Cost: a migration over a table currently at 1.4 GB, plus a rewrite of every write path that assumes a string.
  2. Generated columns for the few fields actually read. balancesTotal and the timestamp cover the overview screen. Keeps message as-is, adds narrow columns the planner can read without touching the document. Cheaper migration, but it duplicates data and only helps known access paths.
  3. Store a pre-aggregated summary row per interval and let the log stay the raw record. Largest change, but it also addresses the write side — see below.

Related: redundancy inside the retention window, now quantified

The producer is LogJobService.saveTradingLog(), running every minute. A cleanup job (keepOnePerDay, Process.LOG_CLEANUP) reduces entries older than the retention window to one per day, so the table is at a steady state (~1.4 GB) and does not grow unbounded — that part is working as designed.

What is measurable inside the window: the assets sub-object is 57 kB of a 59 kB document (96 %), and it is unchanged from its predecessor in 796 of 1140 consecutive pairs (69.8 %). It stays unchanged for 3.3 runs on average, up to 44 runs (~55 minutes). Only 342 distinct assets values occur across 1141 entries in 24 h.

assets is not unused — it is read by the reconciliation service and for the per-asset prices. But writing the identical 57 kB object 3.3 times in a row means the parse cost above is paid on largely duplicated content.

Skipping the write when assets is unchanged (and resolving to the last differing entry on read) would cut roughly 70 % of both the stored volume and the parse work, without changing what any consumer can observe.

Not verified

No production EXPLAIN was taken with a jsonb column in place, because that requires the migration. The 85 MB figure is sum(length(message)) over the window and is exact; the projected speedup is not.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions