Commit 646d91
2026-08-16 19:26:45 Anonymous: -/-| /dev/null .. Why performance is so bad.md | |
| @@ 0,0 1,95 @@ | |
| + | # Why performance is so bad |
| + | |
| + | I reproduced this with a synthetic 2000-page wiki and profiled it. Here's what's going on. |
| + | |
| + | How titles are fetched |
| + | Titles aren't stored in the database as titles. Each entry's title comes from two places: |
| + | |
| + | The filename — via get_pagename / get_pagename_for_title (helper.py:184). |
| + | The page's first Markdown heading, used to fix the capitalization (this happens whenever RETAIN_PAGE_NAME_CASE is off, which is the default). This is the ftoc = get_ftoc(f) call at pageindex.py:133. |
| + | get_ftoc (helper.py:373) is the database part, and it runs once per page: stat the file for its mtime, compute sha256("ftoc://<filename>"), then issue one ORM SELECT against the cache table (models.py:79) filtered on key == hash AND datetime >= mtime. On a miss it reads the file, runs the full Markdown renderer, and writes the row back with its own db.session.commit() (helper.py:350). |
| + | |
| + | So for 2000 pages the index does 2000 stats + 2000 separate SELECTs — and on a cold cache also 2000 file reads, 2000 Markdown parses, and 2000 commits. Separately, the sidebar re-reads the first 512 bytes of all 2000 files to get the same headers again (sidebar.py:160); it doesn't share the ftoc cache. |
| + | |
| + | Measured breakdown (2000 pages, 5 headings each) |
| + | Warm request ≈ 1.0s, cold ≈ 4.0s. Of the 0.85s spent in PageIndex(): |
| + | |
| + | time note |
| + | get_ftoc() × 2001 0.399s same rows via one bulk IN query: 0.024s |
| + | has_children scan (pageindex.py:172-175) 0.256s O(n²): 4,010,273 startswith calls. Same answer from a set of directory prefixes: 0.001s |
| + | url_for / get_pagename / split_path / storage.exists ~0.2s 12k+ url_for calls |
| + | The DB itself is not the bottleneck — SQLite's own execute time for those 2000 queries is 0.065s. Running the identical 2000 SELECTs through raw DBAPI takes 0.031s versus 0.399s through the ORM. It's ~200µs of SQLAlchemy per-query overhead, multiplied by page count. |
| + | |
| + | Cold path: Markdown parsing all pages is 1.296s, and update_ftoc_cache's per-page commit is 0.918s — the same writes in a single commit take 0.072s. |
| + | |
| + | Why yours is 6s and not 1s |
| + | The index emits a link for every heading of every page, each with its own url_for: |
| + | |
| + | headings/page cold warm HTML |
| + | 0 2.5s 0.84s 1.0 MB |
| + | 5 3.8s 0.98s 3.6 MB |
| + | 15 6.2s 1.15s 8.8 MB |
| + | 30 9.6s 1.52s 16.5 MB |
| + | All of that heading markup goes into a <div class="pagetoc"> that is display:none on load (snippets/pageindex.html) — it's hidden behind the "Toggle page headings" switch. So the bulk of the payload and the parse cost is for content nobody sees until they flip that switch. |
| + | |
| + | Two things also keep the cache from being warm: |
| + | |
| + | Cache validity is Cache.datetime >= file mtime. I verified that after a fresh git clone of the repo, 2001/2001 entries are stale — checkout rewrites mtimes. Every redeploy or container rebuild pays the full cold cost. |
| + | The default SQLALCHEMY_DATABASE_URI is sqlite:///:memory: (server.py:53). The Docker entrypoints override it with a file, but a plain install without that setting keeps the cache in memory, so every restart — and every gunicorn worker independently — starts cold. |
| + | Where the wins are |
| + | Roughly in order of payoff, if you want me to implement any of these: |
| + | |
| + | Batch the ftoc lookups — one WHERE key IN (...) query before the loop instead of 2000. ~0.38s, and it's the single biggest warm cost. |
| + | Replace the has_children scan with a precomputed set of directory prefixes. ~0.25s for a few lines. |
| + | Don't emit per-heading TOC entries into the initial page (or make them opt-in / lazy). This is what turns 1s into 6s on heading-heavy wikis, and it's hidden by default anyway. |
| + | Single commit in the cold rebuild instead of one per page. ~0.85s off first load. |
| + | Make cache validity content-based (git blob SHA) rather than mtime, so redeploys don't invalidate everything. |
| + | pageindex.py |
| + | Wait, what do you mean by commit? Are there 2000 git commits made for every page load? |
| + | No — SQLite transaction commits, not git commits. Sorry for the ambiguous word. Let me make it concrete: |
| + | |
| + | Read helper.py (lines 351-372) |
| + | Bash Verify no git commits occur on index load |
| + | IN |
| + | cd /tmp/claude-1000/-home-tadeo-code2-otterwiki/dfaab8e6-d048-4e29-b117-5886b952377e/scratchpad && cat > gitcheck.py <<'EOF' |
| + | import os |
| + | from timeit import default_timer as timer |
| + | BASE = "/tmp/claude-1000/-home-tadeo-code2-otterwiki/dfaab8e6-d048-4e29-b117-5886b952377e/scratchpad/wiki" |
| + | os.environ["OTTERWIKI_SETTINGS"] = os.path.join(BASE, "settings.cfg") |
| + | from otterwiki.server import app, storage, db |
| + | from otterwiki.models import Cache |
| + | client = app.test_client() |
| + | def ncommits(): |
| + | return int(storage.repo.git.rev_list("--count", "HEAD")) |
| + | with app.app_context(): |
| + | Cache.query.delete(); db.session.commit() # force the cold path |
| + | before = ncommits() |
| + | t = timer(); client.get("/-/index"); print("cold index load: %.3fs" % (timer()-t)) |
| + | after = ncommits() |
| + | with app.app_context(): |
| + | print("cache rows written:", Cache.query.count()) |
| + | print("git commits before:", before, " after:", after, " -> created:", after - before) |
| + | print("git dirty:", storage.repo.is_dirty(), " untracked:", len(storage.repo.untracked_files)) |
| + | EOF |
| + | ./venv/bin/python gitcheck.py 2>&1 | tail -6 |
| + | |
| + | OUT |
| + | *** Starting An Otter Wiki 2.23.0 |
| + | cold index load: 3.836s |
| + | cache rows written: 2001 |
| + | git commits before: 1 after: 1 -> created: 0 |
| + | git dirty: False untracked: 0 |
| + | Shell cwd was reset to /home/tadeo/code2/otterwiki |
| + | Confirmed: zero git commits. The index load created 0 commits and left the repo clean, while writing 2001 cache rows. |
| + | |
| + | What I meant is db.session.commit() at helper.py:370 — a SQLAlchemy session commit, i.e. one SQLite transaction commit. update_ftoc_cache is called once per page, and each call ends its own transaction, so a full cold rebuild ends 2000 separate transactions instead of one. |
| + | |
| + | Two clarifications on my earlier phrasing: |
| + | |
| + | It's per cache miss, not per page load. get_ftoc only calls update_ftoc_cache when the cache lookup fails (helper.py:398). On a warm cache the index does 2000 reads and zero writes. The 0.918s figure applies to a cold rebuild — first load after a restart, or after a redeploy resets file mtimes. |
| + | |
| + | Why 2000 transactions costs ~0.9s: each commit is durability-bound (SQLite syncs at transaction end), so you pay per-transaction overhead 2000 times rather than once. That's the 0.918s → 0.072s difference I measured. On a server with slower or network-backed storage this gap gets considerably wider than it is on my local disk. |
| + | |
| + | Worth noting while you're looking at this function: line 362 does another SELECT to check whether the key already exists — on top of the one get_ftoc just performed at helper.py:378. So a cold page costs 2 SELECTs plus a commit, and all three collapse into batched operations if the loop is restructured. |
| + | |
| + | The git side of a page load is only reads — os.walk for the file list, plus open() on the working copy. No git command runs at all on the index path. |
