nick-doc/Issues/ISSUE-136-backend-api-profiling-mongo-hot-path-cache-query-fanout.md

---
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