Add tickets MPS-4 and MPS-5 for 502 worker recycling fix
MPS-4: Eliminate intermittent 502s via uwsgi config tuning MPS-5: Investigate root cause of worker memory growth (~40MB/min)
This commit is contained in:
parent
faefd94abf
commit
d9a565b57a
2 changed files with 241 additions and 0 deletions
115
docs/tickets/mps-4.md
Normal file
115
docs/tickets/mps-4.md
Normal file
|
|
@ -0,0 +1,115 @@
|
|||
# MPS-4: Eliminate intermittent 502s from uWSGI worker recycling
|
||||
|
||||
## Problem
|
||||
|
||||
Visitors intermittently see 502 Bad Gateway errors that resolve on refresh.
|
||||
Root cause: uWSGI workers hit the `--reload-on-rss 256` memory limit every
|
||||
4-5 minutes under normal watch mode traffic, triggering a kill+respawn cycle.
|
||||
With only 2 workers (`--processes=2`), when both recycle near-simultaneously
|
||||
Caddy's `reverse_proxy` gets no available backend and returns 502.
|
||||
|
||||
### Evidence (2026-02-11 ~09:15-09:22 UTC)
|
||||
|
||||
**Worker memory growth** (from `ps aux`):
|
||||
- Worker 882747 (spawned 09:18): 242MB RSS after 4 minutes
|
||||
- Worker 882737 (spawned 09:17): 188MB RSS after 5 minutes
|
||||
- Both approaching the 256MB kill threshold simultaneously
|
||||
|
||||
**Worker recycling frequency** (from `journalctl`):
|
||||
```
|
||||
09:15:24 - worker 2 (882687) "Seeya!" → killed → Respawned as 882699
|
||||
09:15:29 - worker 1 (882640) "Seeya!" → killed → Respawned as 882708
|
||||
09:15:39 - worker 2 (882699) "Seeya!" → killed → Respawned as 882717
|
||||
09:17:36 - worker 2 (882717) "Seeya!" → killed → Respawned as 882737
|
||||
09:18:22 - worker 1 (882708) "Seeya!" → killed → Respawned as 882747
|
||||
```
|
||||
|
||||
Workers survive only ~15 seconds to ~3 minutes under load before hitting
|
||||
the RSS limit. The 09:15:24 and 09:15:29 kills are only 5 seconds apart —
|
||||
both workers recycling nearly simultaneously.
|
||||
|
||||
**Cold start penalty**: First request after respawn takes 400-600ms
|
||||
(vs normal 100-130ms) while the app re-initializes:
|
||||
- 882699 first request: 413ms
|
||||
- 882717 first request: 409ms
|
||||
- 882747 first request: 533ms
|
||||
|
||||
**System resources**: 4GB total RAM, 1.9GB swap used — memory pressure.
|
||||
|
||||
### Current uWSGI config
|
||||
|
||||
```
|
||||
--reload-on-rss 256
|
||||
--processes=2
|
||||
--threads 8
|
||||
--max-requests 10000
|
||||
--http=127.0.0.1:6001
|
||||
```
|
||||
|
||||
## Solution
|
||||
|
||||
Tune uWSGI config to prevent simultaneous worker unavailability:
|
||||
|
||||
### 1. Raise RSS limit
|
||||
|
||||
Raise `--reload-on-rss` from 256 to 512. Workers currently grow to 242MB
|
||||
in 4 minutes — 256 is too aggressive and causes constant churn. At 512MB
|
||||
with 2 workers, worst case is ~1GB for workers, still well within the 4GB
|
||||
system budget (Caddy + master + crypto_watcher use ~300MB combined).
|
||||
|
||||
### 2. Add `--reload-on-rss-stagger`
|
||||
|
||||
If available in the installed uWSGI version, or use `--max-requests` with
|
||||
variance (`--max-requests-delta`) to prevent both workers from recycling at
|
||||
the same instant. Set `--max-requests-delta 1000` to add randomness
|
||||
(each worker gets max-requests ± 1000).
|
||||
|
||||
### 3. Use lazy-apps mode
|
||||
|
||||
Add `--lazy-apps` so each worker loads the application independently after
|
||||
fork. This costs a bit more memory but means the master doesn't need to
|
||||
re-fork the full app — workers initialize in parallel and the surviving
|
||||
worker keeps serving while the new one starts.
|
||||
|
||||
### 4. Add `--harakiri` timeout
|
||||
|
||||
Add `--harakiri 30` as a safety net — if any request takes >30 seconds
|
||||
(stuck DB query, deadlock), kill that worker instead of blocking a slot
|
||||
forever.
|
||||
|
||||
### Proposed new config
|
||||
|
||||
```
|
||||
--reload-on-rss 512
|
||||
--processes=2
|
||||
--threads 8
|
||||
--max-requests 10000
|
||||
--max-requests-delta 2000
|
||||
--harakiri 30
|
||||
--die-on-term
|
||||
--http=127.0.0.1:6001
|
||||
--lazy-apps
|
||||
```
|
||||
|
||||
## Testing
|
||||
|
||||
1. Apply config change on prod (`systemctl edit --full my.makepostsell.com`)
|
||||
2. `systemctl restart my.makepostsell.com`
|
||||
3. Monitor with: `watch -n 5 'ps -o pid,rss,vsz,etimes,cmd -p $(pgrep -f "uwsgi.*make_post")'`
|
||||
4. Verify no 502s during a full watch mode auto-play cycle
|
||||
5. Monitor swap usage — if swap grows past 2.5GB, back off to 384MB limit
|
||||
|
||||
## Risk
|
||||
|
||||
Low. Config-only change, easily reversible with a service restart.
|
||||
The service unit is managed by salt (`/home/fox/foxhop-pillar/caddy/makepostsell.sls`)
|
||||
so the salt pillar should be updated after validating the new values.
|
||||
|
||||
## Depends On
|
||||
|
||||
Nothing. Can be applied immediately.
|
||||
|
||||
## Blocks
|
||||
|
||||
MPS-5 (memory investigation — the RSS tuning buys time but doesn't fix the
|
||||
underlying memory growth).
|
||||
126
docs/tickets/mps-5.md
Normal file
126
docs/tickets/mps-5.md
Normal file
|
|
@ -0,0 +1,126 @@
|
|||
# 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:
|
||||
|
||||
```python
|
||||
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:
|
||||
|
||||
```python
|
||||
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).
|
||||
Loading…
Add table
Add a link
Reference in a new issue