--- issue: 136 title: "Backend: API profiling shows Mongo hot paths are index-backed but still do avoidable repeated reads" severity: low domain: Performance labels: [performance, backend, mongodb, caching] status: open created: 2026-05-31 source: Live dev performance profiling 2026-05-31 --- # Backend: API profiling shows Mongo hot paths are index-backed but still do avoidable repeated reads **Severity:** low **Domain:** Performance **Labels:** performance, backend, mongodb, caching ## Description Live profiling on `dev.manwe.qzz.io` after the direct Caddy cutover showed the tested API routes are still Mongo-backed, not Postgres-backed. Postgres `pg_stat_statements` recorded no application SQL for these request windows; the only SQL activity came from profiling probes and database housekeeping. The good news: the Mongo queries that did run were using indexes and were effectively sub-millisecond on the tiny dev dataset. The useful optimization work is therefore not "fix a slow scan" yet, but reducing repeated query fan-out and avoiding unnecessary reads before real data volume grows. ## Profiling Snapshot Environment: - Backend `2.6.84` - Public entrypoint: `https://dev.manwe.qzz.io` through Caddy -> local nginx -> backend - MongoDB `6.0.28`, bounded `system.profile` capture with `slowms: 0` - PostgreSQL `18.4`, `pg_stat_statements` enabled - Docker block I/O deltas sampled per endpoint window Representative results: | Endpoint | Result | Mongo profile | |---|---:|---| | `GET /api/marketplace/categories` | 40 req, avg 296ms, p99 721ms | 1 total `categories` query across the window; Redis category cache is working | | `GET /api/marketplace/categories/tree` | 40 req, avg 319ms, p99 763ms | 40 `categories` queries, 24 docs/request, `IXSCAN { isActive: 1 }` | | `GET /api/marketplace/sellers` | 20 req, avg 306ms, p99 722ms | 1 `users` query/request, `IXSCAN { role: 1 }` | | `GET /api/marketplace/request-templates/public/:shareableLink` | 20 req, avg 315ms, p99 781ms | 3 queries/request: template by `shareableLink`, seller by `_id`, category by `_id` | | `GET /api/payment/request-network/options?sellerId&templateId` | 293 req, avg 270ms, p99 806ms | 2 queries/request: `requesttemplates` by `_id`, `shopsettings` by `sellerId` | | `GET /api/addresses` | 15 req, avg 315ms, p99 722ms | 1 `addresses` query/request, `IXSCAN { userId: 1 }` | | `GET /api/marketplace/purchase-requests/my` | 15 req, avg 314ms, p99 702ms | 3 queries/request: request list, request count, payment lookup | | `POST /api/auth/login` | 5 req, avg 691ms, p99 1058ms | user find + user updates; Mongo time rounded to 0ms, so latency is likely bcrypt/JWT/update path rather than query scan | Disk write notes: - Mongo profiler itself wrote about 1 MB in some windows; this is measurement overhead, not normal app write load. - Scanner wrote small background chunks, about 17-24 KB, unrelated to the tested API routes. - No meaningful app SQL write/read pressure appeared in the API windows. ## Recommended Work 1. Cache `GET /api/marketplace/categories/tree`. - `getAllCategories()` already uses Redis via `cacheService`. - `getCategoryTree()` re-queries Mongo every request even though it uses the same active category set. 2. Add a short TTL cache for resolved payment rails. - Cache by `(sellerId, templateId)` or a normalized key. - Invalidate on template payment config updates and shop settings updates. - This removes two Mongo reads from every checkout options poll. 3. Avoid empty payment lookups in `getPurchaseRequestsByBuyer`. - The profiled buyer had no matching requests, but the code still performed a `payments` lookup with `purchaseRequestId: { $in: [] }`. - Short-circuit when the page result is empty. 4. Add or confirm compound indexes before the dataset grows. - `PurchaseRequest`: `{ buyerId: 1, createdAt: -1 }` - `Address`: `{ userId: 1, primary: -1, createdAt: -1 }` - `User`: consider `{ role: 1, isEmailVerified: 1 }` for public seller lists. 5. Keep `pg_stat_statements` enabled and add a repeatable profiling script. - The dev server now has SQL statement profiling available. - `nick-doc/scripts/profile-mongo-api.mjs` runs the Mongo profiler around the same endpoint matrix and emits JSON/Markdown so future Postgres migrations can be compared cleanly. ## Affected Files - `backend/src/services/marketplace/CategoryService.ts:38` — category tree bypasses the existing category cache. - `backend/src/services/payment/sellerPaymentConfig.ts:44` — payment rail resolver performs per-call template/shop lookups. - `backend/src/services/marketplace/RequestTemplateService.ts:465` — public template fetch fans out to template, seller, and category queries. - `backend/src/services/marketplace/PurchaseRequestService.ts` — buyer list should skip downstream payment lookup when no request IDs exist. - `backend/src/services/address/addressController.ts:23` — address list is index-backed; compound sort index should be confirmed. ## Acceptance Criteria 1. `categories/tree` uses the same cached category source as `categories` and invalidates on category writes. 2. Payment options with `sellerId` + `templateId` returns from cache for repeated calls and invalidates on relevant seller/template settings changes. 3. Empty purchase request result pages do not issue a `payments` query. 4. Required compound indexes are present in model definitions or migration/startup index setup. 5. A repeatable profiling command records per-endpoint latency, Mongo query groups, and block I/O deltas; SQL profiling remains available through the separate `pg_stat_statements` pass. ## Latest Repeatable Mongo Profile Generated report: - `09 - Audits/Mongo API Profiles/2026-05-31T14-26-19-969Z/summary.md` - `09 - Audits/Mongo API Profiles/2026-05-31T14-26-19-969Z/mongo-api-profile.json` This pass used the script's `RESET_BACKEND_LIMITER=1` option to restart the dev backend first. That clears the process-local `express-rate-limit` global limiter, so authenticated endpoint windows profile Mongo queries instead of stale 429 responses. Clean run highlights: | Endpoint | Requests | Non-2xx | Mongo ops | Top Mongo profile | |---|---:|---:|---:|---| | `GET /api/marketplace/categories/tree` | 10 | 0 | 10 | `categories` find, `IXSCAN { isActive: 1 }`, 24 docs/request | | `GET /api/payment/request-network/options?sellerId&templateId` | 50 | 0 | 100 | `requesttemplates` IDHACK + `shopsettings` by `sellerId` every request | | `GET /api/addresses` | 10 | 0 | 10 | `addresses` find, `IXSCAN { userId: 1 }`, sorted by `primary` and `createdAt` | | `GET /api/marketplace/purchase-requests/my` | 10 | 0 | 30 | list + count + unnecessary `payments` query with `purchaseRequestId: { $in: [] }` | | `POST /api/auth/login` | 5 | 0 | 15 | indexed user find plus user update operations; latency is outside Mongo query time | ## Repeatable Mongo Profiling Command ```bash cd nick-doc RESET_BACKEND_LIMITER=1 \ BASE_URL=https://dev.manwe.qzz.io \ SSH_HOST=root@5.78.213.189 \ SSH_KEY=~/CascadeProjects/wzp \ node scripts/profile-mongo-api.mjs ``` The script enables Mongo `system.profile` only for each bounded endpoint window, groups captured query shapes by namespace/plan/query shape, writes a raw JSON profile and a Markdown summary under `09 - Audits/Mongo API Profiles/`, then disables profiling again. Leave `RESET_BACKEND_LIMITER` unset when you do not want the script to restart the dev backend. ## References - Live profiling on `dev.manwe.qzz.io` — 2026-05-31 - Caddy direct-path profiling pass after Pangolin/newt removal