Jakub Zych
e1703c7489
Purge token set on UAT, restart at 2026-10-10T17:57:57Z, smoke, token-match and purge-ok pass. posts-unchanged, translations-unchanged, category-purged and category-fresh pass after the human re-saves. Debug sessions for G-16.2-1 and G-16.2-2 resolved.
123 lines
14 KiB
Markdown
123 lines
14 KiB
Markdown
---
|
||
status: resolved
|
||
trigger: "UAT gap G-16.2-2: Updated content in https://uat.grzybyfunkcjonalne.pl/gfadmin/golem15/journal/categories/2 (\"Te grzyby, szczególnie\" changed into \"Te grzyby, a szczególnie\") and i see the change in backend even after refresh but not on frontend"
|
||
created: 2026-10-10T17:20:00+02:00
|
||
updated: 2026-10-10T20:05:00+02:00
|
||
goal: find_root_cause_only
|
||
---
|
||
|
||
## Current Focus
|
||
|
||
hypothesis: CONFIRMED (H3) — the host Nuxt app's Nitro swr route cache (`routeRules '/**': { swr: 300 }`) served /cordyceps rendered at 14:59:08 UTC, before the first save; every check the user made (14:59:52–15:00:30) was inside the 300 s fresh window, so Nitro returned that entry without revalidating, and nothing purges it on admin save. The save, the DB and the API are correct.
|
||
test: done — DB SELECTs, API GET, two Nuxt GETs straddling a lazy revalidation, nginx access log timeline, deployed nitro.mjs cache code
|
||
expecting: n/a
|
||
next_action: return ROOT CAUSE FOUND (goal: find_root_cause_only); the gap is a cache-window/UAT-procedure issue, plus a product decision whether editors need instant visibility (purge on save)
|
||
bug_class: Bohrbug (deterministic: any page view within maxAge of the last render returns the cached entry; the first view after expiry returns it too)
|
||
reasoning_checkpoint:
|
||
hypothesis: "The site showed the old text because Nitro's swr route cache for /** (maxAge 300 s, swr: true, in-memory) held a /cordyceps render from 14:59:08 UTC; all the user's post-save views (last at 15:00:30) were before that entry expired at 15:04:08, and Nitro only re-renders an entry when a request arrives after expiry (serving the stale copy to that request). No code path invalidates the entry when the admin saves."
|
||
confirming_evidence:
|
||
- "DB row 2 and GET /_journal/api/v1/categories return the new text with identical md5 4053158bd1a58eb7f9547c18cb5a1724"
|
||
- "127.0.0.1:3016/cordyceps at 15:24:01: last-modified 14:59:08, old text; at 15:25:00: last-modified 15:24:01, new text"
|
||
- "nginx access log: render 14:59:08, PUTs 14:59:48–15:00:27, user views 14:59:52–15:00:30 all 13269 bytes or 304, no further views until 15:23"
|
||
- "deployed nitro.mjs: /** cache { swr: true, maxAge: 300 }; get() returns the unexpired entry without resolving and the expired entry stale-first"
|
||
falsification_test: "If a /cordyceps GET more than 300 s after the save, followed by a second GET, still returned the old text, or the access log showed a user view after 15:04:08 that returned old content and a later one that also did, the hypothesis would be wrong. Observed: post-expiry GET pair returned old then new, exactly as predicted."
|
||
fix_rationale: "Not applicable (diagnose only). Any fix must either shorten/bypass the cache for editors or invalidate the Nitro cache entry on save; changing the 16.2 save path cannot help, because the save is already correct."
|
||
blind_spots: "I did not observe the user's browser directly (no client-side cache test), but the access log shows their requests reaching Nuxt and getting the cached body. The swr cache key for _payload.json follows the same rule and was not separately timed. I did not verify whether the 7 PUTs each changed content (only the final state matters)."
|
||
candidate_causes:
|
||
- "config: Nitro routeRules swr 300 s with no purge on save (CONFIRMED)"
|
||
- "code: save writes a different column/locale than the API reads (ELIMINATED — one column, no translation rows)"
|
||
- "code: Go API caches or returns a stale field (ELIMINATED — API md5 == DB md5)"
|
||
- "environment: nginx proxy_cache (ELIMINATED — none; reproduced on 127.0.0.1:3016)"
|
||
- "environment: broken swr revalidation (ELIMINATED — refresh observed at 15:24:01, no SWR errors logged)"
|
||
- "data: phrase rendered from elsewhere (ELIMINATED — grep of app/layer/build/posts)"
|
||
- "process: UAT step 'the site shows the change' omits the swr window (CONTRIBUTING)"
|
||
and_gate: "yes — the visible failure needed the swr cache with no invalidation AND the user viewing the page only within the 300 s window of a render made just before the edit (their own 14:59:08 view). With either one absent (no cache, or a second view after 15:04:08) the change would have shown."
|
||
|
||
## Symptoms
|
||
|
||
expected: changing one word in a Journal category body in the admin and saving shows no removal notice, and the public site shows the change (Phase 16.2 D-19)
|
||
actual: the save persisted (admin shows "Te grzyby, a szczególnie" after reload), no error reported, but the public Nuxt site still shows "Te grzyby, szczególnie"
|
||
errors: none reported
|
||
reproduction: UAT Test 2 — edit category 2 body at https://uat.grzybyfunkcjonalne.pl/gfadmin/golem15/journal/categories/2, save, view the public category page
|
||
started: discovered during Phase 16.2 UAT, edit made ~2026-10-10 17:00 CEST
|
||
|
||
## Eliminated
|
||
|
||
- hypothesis: H1 — two columns or a translation row: the admin saves one column/locale and the site renders another that is not regenerated
|
||
evidence: golem15_journal_categories has a single `content` column (no content_html); row 2 updated_at 2026-10-10 15:00:27.94 UTC holds "Te grzyby, a szczególnie" at char 589 and no old phrase; golem15_translate_attributes/indexes have no category rows (only 4 Post rows); en locale is disabled
|
||
timestamp: 2026-10-10T15:22Z
|
||
|
||
- hypothesis: H2 — the public Journal API returns old content (server-side cache in Go, or a different field)
|
||
evidence: GET http://127.0.0.1:8096/_journal/api/v1/categories?include_empty=1 on the UAT host at 15:24:13 UTC returns category 2 content with "Te grzyby, a szczeg" at 577, no old phrase, md5 4053158bd1a58eb7f9547c18cb5a1724 == DB md5(content); no cache headers
|
||
timestamp: 2026-10-10T15:24Z
|
||
|
||
- hypothesis: H3 variant — the Nitro swr cache is broken (background revalidation errors or hangs, so the entry never refreshes)
|
||
evidence: the first GET after expiry (15:24:01) triggered a refresh; the next GET (15:25:00) carried last-modified 15:24:01 and the new text; no `[cache] SWR handler error` in /var/log/supervisor/grzybyfunkcjonalne-nuxt.log
|
||
timestamp: 2026-10-10T15:25Z
|
||
|
||
- hypothesis: H3 variant — an nginx proxy cache serves stale pages
|
||
evidence: sites-enabled/uat.grzybyfunkcjonalne.pl has no proxy_cache; the stale page reproduced against 127.0.0.1:3016 directly (bypassing nginx)
|
||
timestamp: 2026-10-10T15:24Z
|
||
|
||
- hypothesis: H4 — the old text is rendered from somewhere else (hardcoded, another category, a post excerpt)
|
||
evidence: no match for the old phrase in the app, the layer, the deployed .output or any post column; it was only in category 2 content, and the refreshed render shows the new phrase
|
||
timestamp: 2026-10-10T15:29Z
|
||
|
||
## Evidence
|
||
|
||
- timestamp: 2026-10-10T15:22Z
|
||
checked: UAT DB, SELECT on golem15_journal_categories (all rows) and golem15_translate_* for category model types
|
||
found: category 2 (cordyceps) content md5 4053158bd1a58eb7f9547c18cb5a1724, length 13903, updated_at 15:00:27.940875 UTC, new phrase present, old phrase absent; no translation rows for categories
|
||
implication: the save persisted the edit in the only column the API reads; the stale copy is downstream of the DB
|
||
|
||
- timestamp: 2026-10-10T15:23Z
|
||
checked: nginx site uat.grzybyfunkcjonalne.pl (sites-enabled) and the host Nuxt app nuxt.config.ts
|
||
found: nginx has no proxy_cache; `/` proxies to Nuxt on 127.0.0.1:3016. nuxt.config.ts routeRules `'/**': { swr: 300 }, '/blog/**': { swr: 120 }` (Nitro route cache on the Node server); category pages are at `/:category` (so /cordyceps falls under `/**` swr 300)
|
||
implication: Nitro's swr route cache is the only HTTP cache between the API and the browser
|
||
|
||
- timestamp: 2026-10-10T15:24Z
|
||
checked: curl -D - http://127.0.0.1:3016/cordyceps on the UAT host (bypasses nginx/basic auth)
|
||
found: 200, `last-modified: Sat, 10 Oct 2026 14:59:08 GMT`, `cache-control: s-maxage=300, stale-while-revalidate`, body contains the OLD "Te grzyby, szczególnie Cordyceps sine"
|
||
implication: Nuxt serves a page rendered 79 s BEFORE the save, 25 min after it — far past the 300 s swr TTL. The cache entry is not being refreshed (H3 territory), or a refresh re-renders from stale data
|
||
|
||
- timestamp: 2026-10-10T15:24Z
|
||
checked: vue-journal-layer app/journal-pages/CategoryPage.vue, app/utils/client.ts, app/composables/useJournalApi.ts and the host override sm-grzybyfunkcjonalne-app/vue-grzybyfunkcjonalne-app/app/composables/useJournalApi.ts
|
||
found: the category page resolves the slug via GET /categories?include_empty=1 and renders found.content through sanitizeJournalHtml; the server fetcher is a plain $fetch to runtimeConfig.journal.apiBase with no cachedFunction/useStorage/getCachedData
|
||
implication: no data-level cache in the layer or app; the only cache is the Nitro route (swr) cache around the page renderer
|
||
|
||
- timestamp: 2026-10-10T15:25Z
|
||
checked: second curl of http://127.0.0.1:3016/cordyceps on the UAT host, 59 s after the 15:24:01 request (also /, /blog, /lions-mane)
|
||
found: /cordyceps now `last-modified: Sat, 10 Oct 2026 15:24:01 GMT` and the body contains the NEW "Te grzyby, a szczególnie"; /lions-mane last-modified 12:40:55, / 14:37:04, /blog 12:40:53 (entries only move when visited after expiry)
|
||
implication: revalidation works; it is lazy. My 15:24:01 GET (first request after expiry) was served the stale page and triggered the background re-render; the next request got the fresh page. Nothing was broken in the render/refresh path at 15:24
|
||
|
||
- timestamp: 2026-10-10T15:26Z
|
||
checked: nginx access log /var/log/nginx/grzybyfunkcjonalne-uat-access.log, 14:00–15:25 UTC, requests to /cordyceps and the categories admin API
|
||
found: 14:59:08 GET /cordyceps 200 13320 (the user's pre-edit view; cache entry mtime = 14:59:08, fresh until 15:04:08). PUT /gfadmin/api/v1/golem15/journal/categories/2 x7 at 14:59:48, 14:59:57, 15:00:06, 15:00:13, 15:00:16, 15:00:23, 15:00:27 (all 200). GET /cordyceps at 14:59:52, 14:59:53 (304), 14:59:54 (304), 14:59:55 (304), 15:00:00 x2, 15:00:07–15:00:09 x6, 15:00:30 — every one 200 13269 or 304 (same etag). No /cordyceps request between 15:00:30 and my 15:23:42 one
|
||
implication: every page view the user made after saving fell inside the 300 s fresh window of the entry rendered at 14:59:08, so Nitro returned it without even scheduling a revalidation; identical 13269-byte bodies and 304s confirm one cached entry was served throughout
|
||
|
||
- timestamp: 2026-10-10T15:27Z
|
||
checked: deployed /srv/grzybyfunkcjonalne/nuxt/.output/server/chunks/nitro/nitro.mjs (defineCachedFunction get(), routeRules, storage mounts)
|
||
found: routeRules `/**` → `cache: { swr: true, maxAge: 300 }`, `/blog/**` → maxAge 120. get(): `expired = ... ttl && Date.now() - entry.mtime > ttl`; not expired → returns the entry, no resolve; expired + swr → returns the stale entry and re-renders in the background (event.waitUntil). Cache storage is the root in-memory driver (only `data` is mounted to fsLite). Nuxt log has no `[cache] SWR handler error`
|
||
implication: the observed behaviour is exactly Nitro swr semantics: an edit becomes visible only after the TTL has expired AND one request has triggered the re-render, i.e. on the second visit after expiry; worst case is unbounded in wall time for a page nobody visits, best case is ~300 s + one throwaway load
|
||
|
||
- timestamp: 2026-10-10T15:28Z
|
||
checked: grep for purge/revalidate/invalidate/swr in sm-journal-plugin, vue-journal-layer, sm-grzybyfunkcjonalne-app; planning docs (16-CONTEXT D-07, DEPLOY.md, host README, 16.2-VERIFICATION)
|
||
found: no cache purge or invalidation hook anywhere (Go save path does not notify Nuxt; Nuxt exposes no purge route). Phase 16 D-07 chose swr deliberately ("a newly published post shows up without a rebuild"), TTLs were Claude's discretion; host README: "a newly published post appears within the TTL"; DEPLOY.md: "The Nuxt page caches (swr) expire by themselves." 16.2-VERIFICATION human item (line 39/211) and the UAT step say "the site shows the change" with no mention of the cache window
|
||
implication: the staleness is designed behaviour of the Phase 16 host app, not a 16.2 regression; the UAT step omitted the wait, and there is no editor-facing way to see an edit immediately
|
||
|
||
- timestamp: 2026-10-10T15:29Z
|
||
checked: grep for "Te grzyby, szczeg" in the host app (app/, i18n/), vue-journal-layer (app/, i18n/), the deployed Nuxt .output, and golem15_journal_posts content/content_html/excerpt
|
||
found: no matches anywhere; the phrase exists only in category 2 content (now edited)
|
||
implication: H4 eliminated — the old text on the site came from the category content in the cached render
|
||
|
||
## Resolution
|
||
|
||
root_cause: "Not a 16.2 save defect. The save, the DB row and the Journal API all carry the edit. The host app's Nitro swr route cache (vue-grzybyfunkcjonalne-app nuxt.config.ts routeRules '/**': { swr: 300 }, deployed as cache { swr: true, maxAge: 300 }, in-memory) served /cordyceps rendered at 14:59:08 UTC. That render came from the user's own pre-edit view, 40 s before the first PUT (14:59:48). Every post-save view (14:59:52 to 15:00:30) fell inside the entry's 300 s fresh window (to 15:04:08), and Nitro returns an unexpired entry without revalidating. Nothing invalidates the entry on admin save: there is no purge hook in sm-journal-plugin, vue-journal-layer or the host app. After expiry, the first view still gets the stale copy and triggers the re-render, so an edit shows only on the second view more than 300 s after the last render. Contributing: the 16.2 UAT/VERIFICATION step 'the site shows the change' does not account for the Phase 16 D-07 swr window."
|
||
fix: (not applied — goal find_root_cause_only)
|
||
verification: "Observed self-healing without any write: 127.0.0.1:3016/cordyceps returned the old text at 15:24:01 UTC (last-modified 14:59:08) and the new 'Te grzyby, a szczególnie' at 15:25:00 (last-modified 15:24:01)"
|
||
files_changed: []
|
||
|
||
## Resolution
|
||
|
||
Fixed by plan 16.2-07 (released as summercms v0.1.20 and vue-journal-layer v0.3.0) and confirmed on UAT on 2026-10-10. See 16.2-07-SUMMARY.md.
|