Memory-Event Log: Tracking Arena Growth

SuperJ allocates through a bump arena — objects are never individually freed; scoped arena {} blocks are dropped en masse. The failure mode to watch for is not a missing free but an unbounded live set: a cache or list that keeps growing, so the arena's reserved bytes climb forever. The memory-event log records arena growth over time so you can find the leak, attribute it to a source location, and do an OOM post-mortem even after a crash.

The 30-second version

# 1. Compile with --mem-track (arms the arena instrumentation)
superj compile myapp.sj --sdk-path $SJ_HOME/sdk --link --mem-track --output myapp

# 2. Run with SJ_MEM_LOG pointing at a path (arms the log at runtime)
SJ_MEM_LOG=tmp/myapp.mlog ./myapp

# 3. Read the log
superj memlog tmp/myapp.mlog

That's it. The log is a binary file (SJML format) written via mmap — no write() syscall per event, no formatting, no allocation on the event path. It survives a SIGKILL (the kernel flushes the mmap'd pages).

How it works

The facility has three enablement tiers, so the default build pays nothing:

--mem-track arms the arena instrumentation in the runtime. SJ_MEM_LOG arms the log at runtime. The two-level design lets you toggle tracing per deploy without a rebuild.

What gets logged

Only chunk-granularity events — the per-object allocation fast path is never touched. A chunk is added every few KB, so there are thousands of events over a whole run, not millions per second.

Two allocation domains

SuperJ has two heaps:

• Arena domain — all new objects. Covered per-event (CREATE/EXPAND/DROP).
• Malloc domain — Strings and maps use malloc directly (hot). Covered by aggregate counters folded into each SNAPSHOT record (live bytes only, not per-call).

The log and the superj memlog report both label this scope honestly.

Reading a log: superj memlog

superj memlog <path>          # one-shot replay
superj memlog --tail <path>   # live-tail a running process

No path defaulting — you pass the log file explicitly. (The runtime defaults to tmp/sj_mem_<pid>.mlog when SJ_MEM_LOG is unset, but superj memlog requires an explicit argument.)

The replay report has five sections:

1. Header

== memory-event log ==
path: tmp/demo.mlog
version: 1  recordSize: 32
pid: 25583  startTsNs: 456213013850041
writeCursor: 13 / capacity: 131072
file bytes: 4194368

The writeCursor is the number of records written; capacity is how many slots the current mapping holds. If the file is smaller than header + writeCursor * 32, the log was truncated (e.g. SIGKILL before kernel flush) — the tool reads what it has and notes the truncation.

2. Events

== events ==
ARENA_CREATE:  4
ARENA_EXPAND:  5
ARENA_DROP:    3
SNAPSHOT:      1
total chunks:  9
live chunks:   9

Counts of each event type. live chunks is the number of arena chunks still alive at the end of the log (not yet dropped).

3. Global

== global ==
final reserved:    18568 bytes
high-water:        50864 bytes
timespan:          350778 ns

The global reserved total (all arenas summed) at the end, and the high-water mark over the whole run. The high-water is the peak memory the process held.

4. Per-arena

== per-arena ==
  arena 1: final=18568  dropped=0  site=<unknown>  LIVE
  arena 2: final=28200  dropped=28200  site=memlog_demo.sj:15  dropped
  arena 3: final=4096  dropped=4096  site=memlog_demo.sj:21  dropped
  arena 4: final=16392  dropped=16392  site=memlog_demo.sj:29  dropped

Each arena's final reserved (if still live) or reserved-at-drop, the bytes freed on drop, and the creation site (file:line where the arena {} block was declared). arena 1 is the global arena (always live, no site).

This is the key section for attribution: if reserved keeps climbing, the arena responsible is the one still LIVE with a large final.

5. Leak verdict + malloc domain + scope

== leak verdict ==
insufficient snapshots for slope — replay the CREATE/EXPAND/DROP timeline above

== malloc domain ==
last snapshot malloc-live: 4200 bytes  (Strings/maps)

== scope ==
arena domain: per-event (CREATE/EXPAND/DROP).
malloc domain (Strings/maps): aggregate in SNAPSHOT.
creation-site attribution: available (3 sites)

The leak verdict compares reserved at the first snapshot vs the end: a positive delta means GROWING (possible leak). The malloc-domain line shows the last snapshot's String/map live bytes. The scope section is honest about what's covered.

Live-tail

superj memlog --tail tmp/myapp.mlog

Polls the log's writeCursor and streams new records as the traced process writes them. Terminates after a ~10-second quiet period (the process has exited). Relies on the runtime's write-record-then-bump-cursor ordering so a half-written slot is never read.

Worked example

The example program $SJ_HOME/demo/memlog_demo.sj simulates a request loop with two scoped arenas:

# Compile with --mem-track
superj compile $SJ_HOME/demo/memlog_demo.sj --sdk-path $SJ_HOME/sdk --link --mem-track \
  --output tmp/memlog_demo

# Run — the log is written to SJ_MEM_LOG (or tmp/sj_mem_<pid>.mlog if unset)
SJ_MEM_LOG=tmp/demo.mlog ./tmp/memlog_demo

# Read the log
superj memlog tmp/demo.mlog

Output (abridged):

processed 5000 requests, sum=122500

== per-arena ==
  arena 1: final=18568  dropped=0       site=<unknown>                LIVE
  arena 2: final=28200  dropped=28200   site=memlog_demo.sj:15   dropped
  arena 3: final=4096   dropped=4096    site=memlog_demo.sj:21   dropped
  arena 4: final=16392  dropped=16392   site=memlog_demo.sj:29   dropped

Arena 1 is the global arena (startup objects, always live). Arena 2 is the requestBatch block at line 15 (28 KB of request results + scratch). Arena 3 is the nested scratch block at line 21. Arena 4 is the cache block at line 29. All three scoped arenas were dropped (their chunks freed), so the final reserved returns to the global arena's 18568 bytes.

If arena 4 (cache) had not been dropped — say you forgot the arena {} block and allocated keys into the global arena — it would show LIVE with a large final, and the global high-water would not come back down. That's the leak signal.

In-process query counters

Two System builtins give you the live reserved/high-water without reading a log file:

long r = System.memReservedBytes();   // current global reserved (arena domain)
long h = System.memHighWaterBytes();  // high-water mark over the process lifetime

Both are live on every build — they are plain counters on the arena chunk malloc/free path, not part of the --mem-track / SJ_MEM_LOG facility (which gates only the mmap event log). They cost two adds on a cold path and need no special build. Useful for self-monitoring (e.g. logging reserved every N requests) and for asserting that scoped memory came back — the delta across a call that opens an arena {} block should be 0:

long before = System.memReservedBytes();
handleRequest(req);
long leaked = System.memReservedBytes() - before;   // want 0

They report reserved chunk capacity (moving in chunk-sized steps, not per-object) and only the arena domain. String bodies are malloc'd and never reclaimed, so a string-building leak grows RSS while these counters stay flat.

Debug build: per-type histogram

For object-level attribution — which types own the live set — a separate debug gate adds a per-type live-bytes histogram. This touches the hot allocation path, so it's confined to a debug build and must never be used in production. The debug build is an advanced feature — see the debug-memory guide for setup instructions.

At exit the histogram prints to stderr:

== memory histogram (debug build) ==
  type                          live_bytes   live_count  alloc_total
  ContentType                        1152           18           18
  ByteArrayBuilder                   1152           36           36
  MsgType                             168            7            7
  PrintStream                          32            2            2

The debug build also poisons freed arena memory with 0xDE when an arena block is dropped, so a use-after-drop read crashes or reads the poison pattern instead of silently reading stale objects.

Wire format

The log file is a versioned 64-byte header followed by fixed 32-byte little-endian records, optionally followed by a trailing site-table section. The format is stable (version 1); the replay tool validates the magic (SJML) and version before reading.