make_post_sell/docs/tickets/mps-5.md

MPS-5: Investigate and fix uWSGI worker memory growth

Problem

uWSGI workers grow from ~83MB (post-fork baseline) to 256MB+ in 4-5 minutes under normal watch mode traffic. This is ~40MB/minute of RSS growth, which is excessive for a Python/Pyramid WSGI application serving 40-80KB HTML/JSON responses.

The rapid growth forces aggressive worker recycling (MPS-4), which causes intermittent 502s. MPS-4 raises the RSS threshold as a band-aid, but this ticket addresses the root cause.

Observed memory timeline

Worker 882747 (spawned 09:18):
  - Baseline after fork: ~83MB (from master RSS)
  - After 4 minutes: 242MB (6.0% of 4GB)
  - Growth rate: ~40MB/min

Potential causes

1. Jinja2 template caching: Each rendered template (62-81KB output) may accumulate compiled template objects. With 8 threads per worker, concurrent renders could multiply this.

2. SQLAlchemy session accumulation: If sessions aren't properly closed after each request, objects pile up in the identity map. The lazy="dynamic" relationships (e.g., shop.products) return query objects that may hold references.

3. Response body retention: uWSGI with --http mode may buffer response bodies in worker memory. The 40-80KB HTML pages add up across threads.

4. Watch mode JSON responses: The /watch/{id}/json endpoint generates 41-51KB JSON responses. Under auto-play, a single visitor generates one of these every 3-7 seconds. If these response strings linger in memory (Python string interning, GC generation 2), they accumulate.

5. Thread-local accumulation: With 8 threads, any per-thread leak is multiplied 8x. Thread-local storage, logging buffers, or connection pools that grow per-thread.

Investigation Plan

Step 1: Add memory logging

Add a tween or middleware that logs RSS after every Nth request:

import resource

def memory_tween_factory(handler, registry):
    counter = [0]
    def memory_tween(request):
        response = handler(request)
        counter[0] += 1
        if counter[0] % 100 == 0:
            rss_mb = resource.getrusage(resource.RUSAGE_SELF).ru_maxrss / 1024
            log.warning("RSS after %d requests: %dMB [%s]",
                        counter[0], rss_mb, request.path)
        return response
    return memory_tween

This tells us which request patterns correlate with memory spikes.

Step 2: Profile with tracemalloc

On a dev instance, enable tracemalloc and compare snapshots:

import tracemalloc
tracemalloc.start()
# ... after N requests ...
snapshot = tracemalloc.take_snapshot()
top_stats = snapshot.statistics('lineno')
for stat in top_stats[:20]:
    print(stat)

Step 3: Check SQLAlchemy session cleanup

Verify that pyramid_tm is properly closing sessions after each request. Check if DBSession.remove() is called in an after_request hook. If using scoped sessions with threads, each thread needs its own session lifecycle.

Step 4: Test with --threads 1

Temporarily run with --threads 1 --processes 4 instead of --threads 8 --processes 2. If memory growth rate drops proportionally, the leak is per-thread. If it stays the same per-worker, it's in shared state.

Step 5: Test without watch mode traffic

Hit only static-ish pages (shop landing, product pages) without the SPA watch mode auto-play. If memory growth slows dramatically, the leak is specific to the /watch/{id}/json or /signals/beacon endpoints.

Solution

Depends on investigation results. Likely fixes:

• If SQLAlchemy sessions: Ensure pyramid_tm transaction manager commits and closes properly per-request. Add explicit DBSession.remove() in a response callback.
• If Jinja2 templates: Set jinja2.cache_size to a bounded value (default is 400, may be unbounded).
• If response bodies: Consider adding --http-keepalive or switching from --http to --http-socket with Caddy using uwsgi protocol.
• If thread-local: Restructure to fewer threads, more processes.

Files Likely Changed

File	Change
__init__.py or tweens.py	Memory logging tween
production.ini	Jinja2 cache_size if needed
systemd service	Thread/process ratio tuning

Depends On

MPS-4 (apply the RSS band-aid first to reduce 502 frequency while investigating).