familysync/.planning/debug/write-path-event-bugs.md

slug, status, trigger, created, updated, phase, branch

slug	status	trigger	created	updated	phase	branch
write-path-event-bugs	resolved	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	2026-06-07	2026-06-08	03-event-write-back-pwa-install	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.