Files
SkinbaseNova/docs/optimization-m11-http-endpoint-performance.md
T
klevze 8a80aae21e Ship production optimization M1-M12.5A: queues, metrics, HTTP observability, and vector search reliability.
Keep similar-ai from tripping the global circuit on a lone URL 502, clamp Qdrant search to 100, and add Server-Timing plus slow-request logging. Studio shared props, Academy S3 exists caching, heat chunking, and Redis/scheduler hygiene stay in this rollout.
2026-08-25 07:58:47 +02:00

323 lines
13 KiB
Markdown
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
# M11 — HTTP Endpoint Performance & Laravel Request Profiling
```text
STATUS: COMPLETE (read-only production HTTP audit + local low-risk fixes)
PRODUCTION: no cache flush, no restarts, no nginx/PHP/MySQL/FPM/Horizon changes
WHEN: 2026-08-23 20:58–21:05 CEST
```
Guest curls from `server3` to `https://skinbase.org` (HTTP/2, `Accept-Encoding: br`). Two sequential requests per path. No concurrency. No cache clears.
M10 snapshot indexes: **unchanged**. Duplicate-index DROP remains unrun; production does not have that index.
---
## 1. HTTP baseline table
Times are TTFB seconds. Size is **compressed** body (brotli) unless noted.
| Path | Status | 1st TTFB | 2nd TTFB | Size (br) | Cache-Control | Encoding |
| ---- | ------ | -------- | -------- | --------- | ------------- | -------- |
| `/` | 200 | 0.449 | 0.413 | ~22 KB | `public, max-age=60, s-maxage=300, swr=600` | br |
| `/` uncompressed HTML | 200 | 0.444 | — | 286 KB | same | none (no AE) |
| `/explore` | 200 | 0.504 | 0.490 | ~16 KB | `no-cache, private` | br |
| `/discover/trending` | 200 | 0.449 | 0.434 | ~8.8 KB | `no-cache, private` | br |
| `/uploads/latest` | 200 | 0.573 | 0.594 | ~11.5 KB | `no-cache, private` | br |
| `/academy` | 200 | **1.283** | 0.838 | ~24 KB | `no-cache, private` | br |
| `/academy/prompts` | 200 | **1.316** | **1.171** | ~29 KB | `no-cache, private` | br |
| `/academy/prompts/popular` | 200 | 0.835 | — | — | private | br |
| `/forum` | 200 | 0.512 | 0.525 | ~15 KB | `no-cache, private` | br |
| `/collections` | **404** | 0.682 | 0.440 | ~8.7 KB | private | br |
| `/collections/featured` | 200 | **1.037** | — | — | private | br |
| `/rss/latest-uploads.xml` | 200 | 0.349 | 0.350 | ~13 KB | `no-cache, private` | br |
| `/sitemap.xml` | 200 | 0.125 | 0.064 | 377 B | `public, max-age=21600` | br |
| `/search?q=skin` | 200 | 0.467 | 0.520 | ~15 KB | private | br |
| `/statistics` | **302 → /login** | 0.309 | 0.254 | 709 B | private | — |
| `/leaderboard` | 200 | 0.439 | 0.435 | ~14 KB | private | br |
| `/staff` | 200 | 0.382 | 0.413 | ~8 KB | private | br |
| `/@killua` (profile) | 200 | **0.975** | **0.968** | 249 KB **uncompressed** | private | — |
| `/favicon.ico` | 200 | 0.063 | — | — | static | — |
No `Server-Timing` header **before** this milestone. Added locally (`AddServerTiming`).
---
## 2. Warm vs second request
| Path | Δ | Interpretation |
| ---- | - | -------------- |
| `/` | −36 ms | Guest homepage `Cache::flexible` working |
| `/sitemap.xml` | −61 ms | Public cache / file cache |
| `/academy` | −445 ms | Application cache (Academy home payload) + SSR warm |
| `/academy/prompts` | −145 ms | Still >1 s — listing + S3 `exists` + SSR |
| Most others | ~0 | Cache already warm; remaining cost is PHP + SSR |
Did **not** flush Redis to manufacture cold tests.
---
## 3. Access-log latency analysis
`/etc/nginx/nginx.conf` uses **default** `access_log` (combined). **No custom `log_format`.**
Missing: `request_time`, `upstream_response_time`, `upstream_connect_time`.
Log file `/var/log/nginx/skinbase.org-access.log` is `www-data:adm` — app user **cannot read** it. **No p95/p99 from access logs.** Do not change nginx during M11.
---
## 4–5. Laravel logs / 5xx
`storage/logs/laravel.log` ~3.5 GB.
**CURRENT (hours around audit):** download warnings for missing originals (not 5xx). No Redis `LOADING`. No Predis memory exhaustion.
**RECENT (same day):** CLI errors (`nova:metrics-prune` not defined, tinker parse, Enhance worker unavailable). Not HTTP user-facing.
**HISTORICAL:** Redis LOADING / presence SMEMBERS / Predis OOM — M7/M8, not recurring in this window.
HTTP 5xx count from nginx: **unknown** (log unread + no timing format).
---
## 6. Middleware cost
Web append: `AddServerTiming` (new), `SecurityHeaders`, `RedirectLegacyProfileSubdomain`, `TrackOnlineVisitor`, `UpdateLastVisit`, `HandleInertiaRequests`, onboarding/email-upgrade.
| Middleware | Per request | Verdict |
| ---------- | ----------- | ------- |
| TrackOnlineVisitor | Redis GET + SETEX + SADD after response; bots included; RSS/sitemaps **now skipped** | LOW after skip |
| UpdateLastVisit | DB update throttled 300s, auth only | NO CHANGE |
| HandleInertiaRequests | auth user + **was** full `studioOptionsForUser` on every auth Inertia page | **HIGH for auth** — gated to `/studio` |
| Session | skipped for some paths via ConditionalStartSession | NO CHANGE |
---
## 7. Inertia shared props
`app/Http/Middleware/HandleInertiaRequests.php::share`
| Prop | Was | Now |
| ---- | --- | --- |
| `auth.user` | profile lazy-load | `load('profile')` once |
| `flash` | closures | same |
| `cdn` / `features` | config | same |
| `studio_groups` | **eager Group::with(owner.profile, members) + whereHas for every logged-in Inertia page** | **only when path starts with `studio`** |
`studio_groups` is consumed only by `resources/js/Layouts/StudioLayout.jsx`.
---
## 8. SSR audit
- Enabled: `config/inertia.php` `ssr.enabled=true`, `http://127.0.0.1:13714`
- Process: `node …/bootstrap/ssr/ssr.js` (www-data)
- Used for Inertia HTML first visits (Academy, forum, leaderboard, collections, profile)
- Home `/` is **Blade**, not SSR
- No SSR duration in logs before Server-Timing
- Do **not** disable SSR globally
- Academy/collections ~1 s likely **SSR + PHP**; second academy hit faster (cache)
---
## 9. Controller mapping (slowest)
| Path | Controller |
| ---- | ---------- |
| `/` | `App\Http\Controllers\Web\HomeController::index` → `HomepageService::all` / `allForUser` |
| `/explore` | `ExploreController::index` (Meilisearch) |
| `/discover/trending` | `DiscoverController::trending` |
| `/academy` | `Academy\AcademyHomeController::index` |
| `/academy/prompts` | `Academy\AcademyPromptController::index` |
| `/leaderboard` | `LeaderboardPageController` → cached `LeaderboardService::getLeaderboard` |
| `/collections/featured` | `CollectionDiscoveryController::featured` (6 discovery queries + SSR) |
| `/search` | `SearchController::index` → Meilisearch + groups + news LIKE |
| `/@user` | `User\ProfileController::showByUsername` |
| `/download/artwork/{id}` | `ArtworkDownloadController` |
| RSS | `RssFeedController::latestUploads` |
---
## 10–11. Query counts / M10 overlap
Local Pest: leaderboard as auth user **0** `groups` / `group_members` queries after the shared-prop gate.
Production EXPLAIN not repeated (M10). HTTP-facing:
- Leaderboard HTTP uses **Cache::remember**, not the 9M snapshot GROUP BY
- Heat job is scheduler, not HTTP
- Browse `/explore` uses Meilisearch then hydrate — TTFB ~500 ms
---
## 12–13. Redis / presence
Per tracked GET: `GET` record, `SETEX` 300s, `SADD` index. No `SMEMBERS` on the request path (M8 SSCAN prune remains).
RSS/sitemaps/robots **were tracked**; now skipped. Bots still tracked on HTML (by design).
---
## 14. Payload
Homepage uncompressed ~286 KB HTML (Inertia-like JSON in Blade). Brotli ~22 KB.
Profile `/@killua` 249 KB uncompressed HTML — large Inertia SSR document. MEDIUM, no rewrite this milestone.
Academy compressed 24–29 KB — fine; TTFB is CPU/S3/SSR not transfer.
---
## 15–21. Surface findings
**Home:** guest flexible cache 5s/30s fresh + 1800s stale. TTFB ~410–450 ms. Personalized `allForUser` uncached (not measured; private).
**Browse:** `/explore` ~500 ms; `no-cache, private` even for guests (CDN cannot cache). MEDIUM documentation only — personalization/maturity may require private.
**Artwork detail:** not sampled with a canonical slug this pass (explore HTML is CDN image URLs). Code path `ArtworkController::show` / web artwork.
**Search:** 467 ms including Meilisearch + optional news `LIKE` on content. Malformed query guard already in `SearchController`.
**Statistics:** auth-gated 302. Rankings `/leaderboard` 439 ms from cache.
**Profile:** ~970 ms both hits — SSR + heavy profile assembly. Documented, no rewrite.
**Academy:** slowest public family. Causes: Inertia SSR + `Storage::exists` on S3 for prompt preview variants + `courseLessons()->count()` when `lessons_count_cache` is 0 (`?:` bug). Fixes: Redis-remember exists 1h; use cache column without extra count.
**Forum:** 512 ms. Existing query-bound tests. Queues stay off.
**RSS:** 350 ms, two queries (`Artwork::published()->with(user)->limit`). Redis not required for generation. Presence writes removed from RSS.
**Download:** production currently logs missing originals **after** incrementing counters — **fixed** (404 first).
---
## 22. External / storage
Academy list `Storage::disk(s3)->exists` per variant — **was synchronous S3 on HTTP**. Now cached 1h.
Download `File::isFile` local originals.
Enhance worker errors are CLI/job, not public pages.
---
## 23. Cache / stampede
Homepage already `flexible` (stale-while-revalidate). Leaderboard `Cache::remember` — stampede possible but 439 ms and scheduled refresh exist. **No new caches** except Academy asset-exists.
---
## 24. Bots / deep pagination
Access logs unreadable. Historical malformed search URLs remain historical. **No UA blocking.**
---
## 25. HTTP cache / compression / static
- gzip + brotli **on** in nginx (confirmed `content-encoding: br` when AE sent)
- Static `favicon.ico` 63 ms, not Laravel
- `/build/*` access_log off in vhost
- Guest `/` already public CDN-friendly; most Inertia HTML `private, no-cache` (auth/session/SSR)
---
## 26. TTFB classification
| Endpoint | Dominant cost |
| -------- | ------------- |
| `/` | PHP bootstrap + cached payload + HTML serialize (~400 ms floor) |
| `/explore`, `/discover/*` | PHP + Meilisearch + Blade/Inertia |
| `/academy*` | **SSR + PHP + (was) S3 exists** |
| `/collections/featured` | **SSR + multiple discovery SQL** |
| `/@user` | **SSR + profile assembly** |
| `/leaderboard` | PHP + Redis cache hit |
| `/sitemap.xml` | static/cached XML |
| `/rss/*` | PHP + small SQL |
---
## 27. Ranked findings
| Severity | Item |
| -------- | ---- |
| HIGH | Auth Inertia `studio_groups` full group graph every page — **fixed** (studio path only) |
| HIGH | Download counters/events before missing-file 404 — **fixed** |
| HIGH | Academy S3 `exists` on listing/home cards — **fixed** (1h cache) |
| MEDIUM | Academy / collections / profile ~1 s (SSR). Do not disable SSR |
| MEDIUM | Guest explore/discover `Cache-Control: private` — CDN cannot cache |
| MEDIUM | `/collections` 404; real routes `/collections/featured` etc. |
| LOW | Presence on RSS — **fixed skip** |
| LOW | `lessons_count_cache ?: count()` extra SQL — **fixed** |
| NO CHANGE | FPM 14, Horizon, Redis size, snapshot indexes, forum queues, MySQL knobs |
---
## 28. Files changed
- `app/Http/Middleware/HandleInertiaRequests.php`
- `app/Http/Middleware/TrackOnlineVisitor.php`
- `app/Http/Middleware/AddServerTiming.php` (new)
- `bootstrap/app.php`
- `app/Http/Controllers/ArtworkDownloadController.php`
- `app/Services/Academy/AcademyAccessService.php`
- `tests/Feature/Http/StudioGroupsSharedPropTest.php`
- `tests/Feature/Http/ArtworkDownloadMissingFileTest.php`
- `tests/Feature/Http/RssPresenceSkipTest.php`
- `docs/optimization-m11-http-endpoint-performance.md`
---
## 29. Tests
```text
pest StudioGroupsSharedPropTest PASS
pest ArtworkDownloadMissingFileTest PASS
pest RssPresenceSkipTest PASS
```
---
## 30. Production deployment plan
1. Deploy application code only.
2. Do **not** run M10 DROP INDEX.
3. Do **not** restart Redis/MySQL/FPM/Horizon except normal PHP-FPM reload for PHP.
4. SSR process already running; no disable.
---
## 31. Post-deploy verification
From `server3`, sequential:
```bash
curl -sS -D - -o /dev/null --max-time 20 -H 'Accept-Encoding: br' https://skinbase.org/academy | grep -iE 'HTTP/|server-timing|cache-control'
curl -sS -o /dev/null -w 'academy ttfb:%{time_starttransfer}\n' -H 'Accept-Encoding: br' https://skinbase.org/academy
curl -sS -o /dev/null -w 'prompts ttfb:%{time_starttransfer}\n' -H 'Accept-Encoding: br' https://skinbase.org/academy/prompts
curl -sS -o /dev/null -w 'home ttfb:%{time_starttransfer}\n' -H 'Accept-Encoding: br' https://skinbase.org/
```
Expect `Server-Timing: app;desc="Laravel";dur=…`. Academy TTFB should move toward the warm ~0.8 s band more often (asset-exists cache). Guest home should stay ~400–450 ms.
---
## 32. Rollback
Revert the listed PHP files. Presence skip and Server-Timing are additive. Download 404-before-increment is the correct semantics (do not roll back unless a download of a missing file must still increment stats — it should not).
---
## Measurement note (acceptance)
Public guest pages already under ~500 ms except Academy (~1.3 s), collections featured (~1.0 s), profile (~0.97 s).
| Path | BEFORE (prod guest) | AFTER (expected) |
| ---- | ------------------- | ---------------- |
| `/` | 0.45 / 0.41 s | same |
| `/academy` | 1.28 / 0.84 s | fewer S3 round-trips; SSR remains |
| `/academy/prompts` | 1.32 / 1.17 s | fewer S3 round-trips |
| Auth non-studio Inertia | unmeasured (group graph every request) | **0 extra group SQL** (tested) |
| Missing download | counters + 404 | **404 only** (tested) |