docs(debug): resolve write-path-event-bugs (timezone + calendar identity)
This commit is contained in:
Lucas Berger
@@ -0,0 +1,90 @@
|
||||
---
|
||||
slug: write-path-event-bugs
|
||||
status: resolved
|
||||
trigger: "Phase 03 Gate 2 Part D — created events have wrong time (4h off) and attach to the wrong user's calendar; poller creates duplicate calendar rows"
|
||||
created: 2026-06-07
|
||||
updated: 2026-06-08
|
||||
phase: "03-event-write-back-pwa-install"
|
||||
branch: gsd/v1.0-milestone
|
||||
---
|
||||
|
||||
# Debug Session: write-path-event-bugs
|
||||
|
||||
## Symptoms
|
||||
|
||||
Two distinct, confirmed write-path bugs found during live Gate 2 Part D testing.
|
||||
|
||||
### BUG A — Event times written 4 hours off (local serialized as UTC)
|
||||
- **Expected:** Create an event for 9:00–10:00am local (operator is in America/Toronto, EDT = UTC−4) → it displays at 9:00–10:00am.
|
||||
- **Actual:** It displays at 5:00–6:00am (−4h).
|
||||
- **Confirmed evidence:** the stored VEVENT for the created event is:
|
||||
```
|
||||
DTSTART:20260607T090000Z
|
||||
DTEND:20260607T100000Z
|
||||
```
|
||||
The user's wall-clock "09:00" was serialized with a `Z` (UTC) suffix instead of being converted to UTC (correct = `130000Z`) or written with a TZID (`DTSTART;TZID=America/Toronto:20260607T090000`). `calendar_events.dtstart_utc` = `2026-06-07 09:00:00`. The DISPLAY side is correct (converts 9am UTC → 5am EDT); the WRITE path is wrong.
|
||||
- **Investigate:** `apps/pwa/src/components/EventForm.tsx` (what datetime string it sends to the API), `apps/api/src/routes/events.ts` (create + edit handlers), and the VEVENT builder `buildVeventString` (grep `buildVeventString` / `DTSTART` under `apps/api/src/broker/`). Decision D-02-RRULE exists re: ICAL.Recur/ICAL.Property serialization.
|
||||
- **Acceptance:** 9am local in → stored as UTC-correct (or TZID) → round-trips → displays 9am local. Add a regression test.
|
||||
|
||||
### BUG B — Created events attach to the wrong user's calendar; poller creates duplicate calendar rows
|
||||
- **Expected:** user 2 (real OIDC, id=2) creates an event → it belongs to user 2's calendar; the poller maintains exactly one calendar row per (userId, collection URL).
|
||||
- **Actual:** the event landed on `calendar_id=1` (owned by user 1, the obsolete spike identity "Dev User", `oidc_iss='spike://cal-08'`). The poller created a NEW calendar row for user 2's "Calendar" collection on every poll.
|
||||
- **Confirmed evidence (DB):** `calendars` has FOUR rows for the same Fastmail collection URL ending `/2180A37A-806E-11EB-872C-AE53E9CB9923/`:
|
||||
- id=1 → user_id=1 (508 events)
|
||||
- id=2, id=4, id=5 → user_id=2 (0 events each) — duplicates created across polls
|
||||
- id=3 → user_id=2 "USA Holidays" (32 events, different URL — synced fine)
|
||||
All "Calendar" events (508) sit under id=1; user 2's "Calendar" rows have 0 events.
|
||||
- **Investigate:**
|
||||
- `apps/api/src/broker/poller.ts` — loops `davCalendars`, looks up the stored calendar via `eq(calendars.url, davCal.url)` WITHOUT a `userId` predicate → cross-user match (finds user 1's row). Strong candidate for the core defect.
|
||||
- `apps/api/src/broker/sync.ts` — calendar upsert (the `.values({` calls ~line 42 and ~105): how it matches/creates the calendar row (is it idempotent on (userId, url)? does it produce duplicates?), and how the event-cache upsert resolves `calendarId` (unique key is (calendarId, uid)) — events end up under the wrong calendarId.
|
||||
- **Acceptance:** exactly one calendar row per (userId, url); a user's created event syncs back under THAT user's calendar row; no duplicate rows accumulate across polls. Add regression test(s).
|
||||
|
||||
## Out of scope (tracked separately — do NOT fix here)
|
||||
- `GET /api/events` missing `userId`/`isShared` filter (returns all users' events).
|
||||
- `me.ts` blank `displayName`/`oidc_iss` (OIDC claim extraction).
|
||||
- Non-animated "Syncing" toast (UI polish).
|
||||
- Stale spike data cleanup (user 1 + calendar id=1 + 508 events) — data, not code; relates to BUG B but handle after the code fix.
|
||||
|
||||
## Environment
|
||||
- Stack running via `docker compose` (production target). Write path works end-to-end (outbox dispatches to Fastmail). These are LOGIC bugs, not infra.
|
||||
- DB access: `docker compose exec -T mariadb mariadb -ufamilysync -p"$(grep -E '^DB_PASSWORD' .env | cut -d= -f2)" familysync -e "..."`
|
||||
- Tests: `pnpm --filter @familysync/api exec vitest run` ; `pnpm --filter @familysync/pwa exec vitest run`. TDD mode is ON.
|
||||
|
||||
## Current Focus
|
||||
|
||||
hypothesis: CONFIRMED. (A) the PWA sent a naive local wall-clock string with no offset; the API container (UTC) parsed it via `new Date()` as UTC, so 09:00 Toronto serialized to `090000Z`. (B) poller looked up + sync selected/upserted calendars by url alone, and the schema had NO unique key on url — so the shared-account collection URL matched the other member's row and each poll inserted a duplicate.
|
||||
next_action: none — root cause confirmed and fixed for both bugs; regression tests green; live DB constraint applied.
|
||||
|
||||
## Evidence
|
||||
|
||||
- timestamp: 2026-06-07 — Stored VEVENT shows `DTSTART:20260607T090000Z` for a 9am-local input (BUG A confirmed at the data layer).
|
||||
- timestamp: 2026-06-07 — `calendars` has 4 rows for the same `…2180A37A…` URL (ids 1/2/4/5); created event landed on calendar_id=1 (user 1); user 2's "Calendar" rows have 0 events (BUG B confirmed at the data layer).
|
||||
- timestamp: 2026-06-08 — BUG A code root cause confirmed: EventForm sent naive `${date}T${time}:00` (no offset); outboxWorker `new Date()` parses it in the UTC container; buildVevent emits `...Z`. Fix: serialize to UTC instant in-browser. Regression test green (5 cases).
|
||||
- timestamp: 2026-06-08 — BUG B code root cause confirmed: no unique key on calendars.url (upsert never deduped) + url-only lookup/select matched the other member's row under the shared Fastmail account (D-16). Fix: (userId,url) unique key + per-user predicates in poller/sync. Regression tests green (fail against buggy url-only predicate).
|
||||
- timestamp: 2026-06-08 — Migration 0001 applied to live DB: duplicate rows ids 4,5 removed; uniq_calendar_user_url present. Full suites: API 98/98, PWA 140/140; tsc clean both packages.
|
||||
|
||||
## Eliminated
|
||||
|
||||
- BUG A is NOT a display-side defect — the read/expand path correctly converts UTC→local; the error is purely in write-path serialization (confirmed by stored `090000Z` for a 9am-local input).
|
||||
- BUG B is NOT an ownership-check bug in the events route — `/create` correctly resolves the user's own calendar; the corruption happens later in the poller/sync cache layer, independent of the write API.
|
||||
|
||||
## Resolution
|
||||
|
||||
### BUG A — write-path timezone serialization
|
||||
- **root_cause:** `EventForm.handleSubmit` sent timed start/end as a naive local wall-clock string (`${date}T${time}:00`, no UTC offset). The outbox worker then ran `new Date(thatString)`, which Node parses in the API container's local timezone (UTC in Docker) — so 09:00 America/Toronto was treated as 09:00 UTC. `buildVeventString` (`ICAL.Time.fromJSDate(d, true)`) then emitted `DTSTART:...090000Z`, displaying back as 05:00 EDT (−4h).
|
||||
- **fix:** Added `apps/pwa/src/lib/eventDateTime.ts` (`serializeEventDateTime`/`localWallClockToUtcIso`). The PWA now converts timed events to an unambiguous UTC instant in the browser (where the operator's zone is known) via `new Date(localParts).toISOString()`; the worker's `new Date(utcIso)` is now container-timezone-independent. All-day events stay `YYYY-MM-DD` DATE strings (D-13). Wired into `EventForm.handleSubmit`. No backend change needed.
|
||||
- **regression test:** `apps/pwa/src/lib/eventDateTime.test.ts` (5 cases): timed → UTC `Z` instant, round-trips to the same local wall clock, equals `new Date(localParts).toISOString()` (not passthrough), all-day stays a DATE string.
|
||||
|
||||
### BUG B — wrong-calendar attach + duplicate calendar rows
|
||||
- **root_cause:** Two faults compounding. (1) `calendars` had NO unique key on `url` (only a non-unique `idx_calendars_user_id`), so the `onDuplicateKeyUpdate` in `syncCalendar`'s calendar upsert never fired → every poll inserted a fresh row for user 2's collection. (2) Both `poller.ts` (ctag lookup) and `sync.ts` (post-upsert id select) matched on `url` alone. Because the two members share ONE Fastmail account (D-16), the same collection URL exists for both; the url-only query returned the lowest-id row (user 1's id=1), so user 2's events were cached under `calendarId=1`.
|
||||
- **fix:**
|
||||
- `apps/api/src/db/schema.ts`: added composite `unique('uniq_calendar_user_url').on(t.userId, t.url)` so the calendar upsert is idempotent per (userId, url).
|
||||
- `apps/api/src/broker/poller.ts`: lookup now `and(eq(userId, cred.userId), eq(url, davCal.url))`.
|
||||
- `apps/api/src/broker/sync.ts`: post-upsert select now `and(eq(userId), eq(url))`; imported `and`.
|
||||
- `apps/api/src/db/migrations/0001_calendars_user_url_unique.sql`: hand-written, idempotent — repoints events off duplicate rows onto the lowest-id keeper per (user_id, url), deletes the loser rows, then adds the unique key. Applied to the live DB (dropped duplicate ids 4,5; key now present).
|
||||
- **regression tests:** `poller.test.ts` + `sync.test.ts` each assert the calendar predicate is scoped to `(user_id, url)` (verified non-vacuous: fails against the buggy url-only predicate); `sync.test.ts` asserts the calendar upsert uses `onDuplicateKeyUpdate`.
|
||||
|
||||
### Verification
|
||||
- API tests: 98/98 pass. PWA tests: 140/140 pass. `tsc --noEmit` clean for both packages.
|
||||
- Live DB post-migration: `calendars` = id1(user1, stale spike data, out-of-scope), id2(user2 Calendar), id3(user2 USA Holidays); `uniq_calendar_user_url` present.
|
||||
- NOT done here (per scope guardrails / broken playwright daemon): image rebuild + tunnel re-test, and stale spike data cleanup (user 1 / calendar id=1 / 508 events). Orchestrator owns these.
|
||||
Reference in New Issue
Block a user