SkinbaseNova/docs/optimization-m12-http-performance-observability.md

M12 — Production Performance Observability & Slow Request Logging

STATUS: COMPLETE (audit + local artifacts; production nginx/FPM/env NOT modified)
WHEN: 2026-08-24 16:46 CEST
PRODUCTION: read-only audit only

This milestone is observability. No application behavior changes except:

• Server-Timing now wraps the full HTTP kernel (prepend) and can add ssr;dur= when Inertia SSR runs
• Slow-request logging is off until HTTP_SLOW_REQUEST_LOG_ENABLED=true

---

1. Current nginx access logging

Item	Production
nginx	1.26.3
log_format	none (default combined)
http default	access_log /var/log/nginx/access.log;
Skinbase vhost	access_log /var/log/nginx/skinbase.org-access.log; (no format → combined)
access_log off	static css/js/images, /photo/*.jpg
Query strings	yes in combined $request
Timing vars	absent
SHA256 nginx.conf	d1720f312b054a2007ffa731158c8bf4c9bd64bba35ba3971551f28cbabd2bd5
SHA256 skinbase.org.conf	4e7e4aa29cb406ccedf3e42613997683a92f1c8e2786bd087adab6012dd4b26f

Multiple vhosts have separate logs. http {} includes /etc/nginx/conf.d/*.conf.

Cloudflare sits in front (server: cloudflare, cf-cache-status: DYNAMIC, 00-cloudflare-realip.conf). Origin request_time is nginx-on-server3, not browser RTT.

---

2. Logrotate

/etc/logrotate.d/nginx:

/var/log/nginx/*.log {
    daily
    rotate 14
    compress
    delaycompress
    create 0640 www-data adm
    postrotate: invoke-rc.d nginx rotate
}

A new /var/log/nginx/skinbase-performance.log is already covered. No extra logrotate rule.

---

3. Current FPM slowlog

Pool /etc/php/8.4/fpm/pool.d/skinbase.conf (SHA256 a0211876…):

Setting	Value
pm.max_children	14 (do not change)
request_terminate_timeout	120s
request_slowlog_timeout	10s (already on)
slowlog	/var/log/php8.4-fpm-skinbase-slow.log (~23 MB)
catch_workers_output	yes
pm.status_path	/fpm-status localhost only

FPM slowlog recommendation: NO CHANGE. 10s is appropriate for rare stacks. Do not lower to 2s in the same deploy as nginx JSON logging.

/fpm-status and /fpm-ping are allow 127.0.0.1; deny all. No public status. No stub_status.

---

4. Existing Server-Timing

Live header (server3 curl /):

server-timing: app;desc="Laravel";dur=96.9
cache-control: max-age=60, public, s-maxage=300, stale-while-revalidate=600

M11 middleware was web-appended, so it missed earlier kernel/session work (TTFB ~0.45 s vs Laravel ~110 ms). M12 prepends it globally so app;dur is closer to full Laravel time. Streamed/download: skip if headers_sent(). No SQL/Redis/cookies in the header.

---

5. Proposed performance log format

File: /var/log/nginx/skinbase-performance.log
Format name: skinbase_perf escape=json
Prepared: deploy/nginx/conf.d/skinbase-perf-log-format.conf
Vhost extra line: deploy/nginx/skinbase-vhost-performance-log.snippet

Existing combined log stays.

Static locations with access_log off stay off (not forced through PHP).

$upstream_* is "-" for static; analyzer treats as null. Fastcgi PHP has numeric upstream times. $upstream_cache_status is typically empty (no nginx proxy_cache for Laravel) — still logged as cache.

---

6. Privacy / security

Logged: time, host, method, $uri (path only), status, timings, bytes, content-type, cache token.

Not logged: IP, cookies, Authorization, query string, POST body, user id, session.

---

7. Expected log volume

Combined Skinbase access log: ~17 MB so far today, ~31 MB yesterday uncompressed; rotated daily 14 days.

JSON lines ~300–400 B. Static already excluded. Estimate ~20–40 MB/day uncompressed, ~300–600 MB retained (14d) before gzip of older copies (~2–4 MB/day gz). Acceptable; no field trim required.

Permissions: nginx 0640 www-data adm. Do not chmod 777. Analyzer may need sudo.

---

8–9. Laravel slow-request logger + threshold

• Middleware: LogSlowHttpRequest (global prepend; no-op when disabled)
• Channel: slow-http → storage/logs/slow-http.log daily, 14 days
• Fields: time, method, route_name, route_uri (template), status, duration_ms, peak_memory_mb, authenticated bool, inertia bool
• Threshold: 750 ms

Rationale: homepage Laravel ~100 ms; guest TTFB 400–500 ms; Academy still 0.6–1.1 s. 750 ms captures Academy/profile/SSR outliers without logging every homepage. If volume is high after 24 h, raise to 1000 ms — do not sample first.

Disable: HTTP_SLOW_REQUEST_LOG_ENABLED=false (default in .env.example).

---

10. SSR timing

TimedInertiaSsrGateway wraps Inertia HttpGateway (no vendor patch, SSR not disabled).

When SSR runs, Server-Timing becomes:

app;desc="Laravel";dur=...
ssr;desc="Inertia SSR";dur=...

app includes SSR (nested). Blade home has no ssr metric.

---

11. FPM slowlog

NO CHANGE (already 10s). Optional later: 2s in a separate change, not bundled with nginx JSON.

---

12–14. Analyzer, URI rules, percentiles

scripts/analyze-http-performance.php + HttpPerformanceLogAnalyzer

Host filter (M12.1): --host=skinbase.org exact match only. Without --host, rows aggregate on host + normalized URI (hosts are never merged).

URI normalization (analysis only): numeric segments → {id}; /@name → /@{user}; UUID → {uuid}; long hex → {hash}; /art/{id}/{slug} vs /art/{id}/similar.

Percentile: nearest-rank, rank = ceil(p * n), 1-indexed. Not an average.

Upstream multi-value: sum numeric comma-separated parts (0.100, 0.220 → 0.32). request_time is authoritative for request latency.

499: counted separately; not treated as 5xx.

---

15–16. Tests

pest tests/Unit/Http/HttpPerformanceLogAnalyzerTest.php   PASS (4)
pest tests/Feature/Http/SlowHttpRequestLoggingTest.php    PASS (5)

Fixtures cover PHP, static -, multi-upstream, 200/302/404/499/500, malformed JSON, /download/artwork/{id}, /@{user}.

---

17. Files changed

• config/http_observability.php
• config/logging.php
• .env.example
• phpunit.xml
• bootstrap/app.php
• app/Providers/AppServiceProvider.php
• app/Http/Middleware/AddServerTiming.php
• app/Http/Middleware/LogSlowHttpRequest.php
• app/Support/Http/HttpUriNormalizer.php
• app/Support/Http/HttpPerformanceLogAnalyzer.php
• app/Support/Http/TimedInertiaSsrGateway.php
• scripts/analyze-http-performance.php
• deploy/nginx/conf.d/skinbase-perf-log-format.conf
• deploy/nginx/skinbase-vhost-performance-log.snippet
• tests + fixtures
• this document

---

18. Nginx files prepared (not installed)

See deploy/nginx/conf.d/skinbase-perf-log-format.conf and skinbase-vhost-performance-log.snippet.

---

19. Env

Production recommended:

HTTP_SLOW_REQUEST_LOG_ENABLED=true
HTTP_SLOW_REQUEST_MS=750
HTTP_SLOW_REQUEST_LOG_DAYS=14

Local default: false.

---

20. Application deploy (A)

1. bash ./sync.sh (do not git pull on production).

2. Add the three env vars to production .env.

3. Config refresh as skinbase, only if the host uses config cache:

   sudo -u skinbase php artisan config:cache

4. Do not run artisan as root. Do not cache:clear globally unless required.

5. PHP-FPM reload only if the deploy process already does (code opcache). No Horizon/Redis/MySQL restart.

---

21. Nginx deploy (B) — separate from app

1. Backup: copy nginx.conf and sites-enabled/skinbase.org.conf.
2. Install skinbase-perf-log-format.conf into /etc/nginx/conf.d/.
3. Add one extra access_log line in the HTTPS server (keep combined).
4. sudo nginx -t — stop if fail.
5. sudo systemctl reload nginx (not restart).
6. One curl to /.
7. Confirm a JSON line in skinbase-performance.log and a combined line in skinbase.org-access.log.
8. Confirm no query string / no IP in JSON.
9. sudo -u skinbase php scripts/analyze-http-performance.php --file=/var/log/nginx/skinbase-performance.log --since=1h --top=10
   (may need sudo to read 0640 www-data adm).

---

22. Optional FPM (C)

Skip. Already logging stacks at 10s.

---

23. Immediate verification

curl -sS -D - -o /dev/null --max-time 20 -H 'Accept-Encoding: br' https://skinbase.org/ \
  | grep -iE 'HTTP/|server-timing|cache-control'

sudo tail -n 1 /var/log/nginx/skinbase-performance.log
sudo tail -n 1 /var/log/nginx/skinbase.org-access.log
sudo -u skinbase tail -n 1 /opt/www/virtual/SkinbaseNova/storage/logs/slow-http-$(date +%F).log

Expect Server-Timing with app;dur= (and ssr;dur= on Inertia pages). Home may be below 750 ms and not appear in slow-http.

---

24. 24h analysis

sudo php /opt/www/virtual/SkinbaseNova/scripts/analyze-http-performance.php \
  --file=/var/log/nginx/skinbase-performance.log --since=24h --top=20

Then --status=5xx, --status=499, --uri=/academy, --slow-ms=1000.

Do not start M13 optimizations from a handful of curls.

---

25. Rollback

• App: HTTP_SLOW_REQUEST_LOG_ENABLED=false then config cache as skinbase. No code revert required for logging.
• Nginx: remove the extra access_log line and/or conf.d file, nginx -t, reload. Combined log untouched.
• SSR timing: revert Gateway bind only if a defect appears (SSR behavior unchanged).

---

26. Risks

• JSON access_log disk (~40 MB/day). Rotation already exists.
• Slow-http volume if many pages >750 ms (raise threshold).
• app;dur will increase vs M11’s ~110 ms because timing now includes earlier middleware (this is more accurate, not a regression).
• Cloudflare still hides client RTT.

---

27. NO CHANGE

FPM pm.max_children, Horizon, MySQL, Redis, snapshot indexes, SSR on/off, Telescope, Debugbar, SQL/Redis tracing, forum/collections queues, load tests, nginx restart, public status pages.