Skip to main content

max / goingson

Testing + arch cold spots: +54 tests, import_external repo refactor, milestone/FTS fixes Tests (+54): user_repo auth (Argon2), stats_repo, backup_settings_repo, task_repo_state focus/scheduling, milestone/saved_views/stats/search commands, sync HLC monotonicity/idempotency/clock-poison/bind_json_value Arch: ContactRepository/EventRepository set_external_ref; import_external.rs drops raw SQL and swallowed ics dedup error Fixes surfaced by tests: MilestoneStatus lowercase db_value now round-trips (was reverting Completed->Open on read); FTS task search excludes soft-deleted tasks Cleanup: strip [timer] debug console.log from time-tracking.js
Co-Authored-By
Claude Opus 4.8 (1M context) <noreply@anthropic.com>
Author: Max Johnson <me@maxj.phd> · 2026-07-04 18:02 UTC
Signed with PGP, not checked
Commit: f902cecdc737ad9ae7138a1451a4b41cd59f60c0
Parent: ea9ba85
17 files changed, +1759 insertions, -24 deletions
@@ -285,6 +285,16 @@
285 285 /// Deletes an event.
286 286 async fn delete(&self, id: EventId, user_id: UserId) -> Result<bool>;
287 287
288 + /// Records the external source/id for an event (e.g. after an iCal import),
289 + /// used to dedup on re-import.
290 + async fn set_external_ref(
291 + &self,
292 + id: EventId,
293 + user_id: UserId,
294 + source: &str,
295 + external_id: &str,
296 + ) -> Result<()>;
297 +
288 298 /// Deletes multiple events by ID, returning the number deleted.
289 299 async fn delete_many(&self, ids: &[EventId], user_id: UserId) -> Result<u64>;
290 300
@@ -968,6 +978,16 @@
968 978 /// Deletes a contact (CASCADE removes sub-entities), returning `true` if deleted.
969 979 async fn delete(&self, id: ContactId, user_id: UserId) -> Result<bool>;
970 980
981 + /// Records the external source/id for a contact (e.g. after a vCard import),
982 + /// used to dedup on re-import.
983 + async fn set_external_ref(
984 + &self,
985 + id: ContactId,
986 + user_id: UserId,
987 + source: &str,
988 + external_id: &str,
989 + ) -> Result<()>;
990 +
971 991 /// Deletes multiple contacts by ID, returning the number deleted.
972 992 async fn delete_many(&self, ids: &[ContactId], user_id: UserId) -> Result<u64>;
973 993
@@ -79,10 +79,8 @@
79 79 * @param {string} taskId - Task ID to track time for
80 80 */
81 81 async function startTimer(taskId) {
82 - console.log('[timer] startTimer called', { taskId, hasApi: !!GoingsOn.api?.timeTracking?.startTimer });
83 82 try {
84 - const result = await GoingsOn.api.timeTracking.startTimer(taskId);
85 - console.log('[timer] startTimer succeeded', result);
83 + await GoingsOn.api.timeTracking.startTimer(taskId);
86 84 await checkActive();
87 85 if (GoingsOn.tasks?.load) GoingsOn.tasks.load();
88 86 } catch (err) {
@@ -177,7 +175,6 @@
177 175 async function loadTimerView() {
178 176 const container = document.getElementById('timer-subview-content');
179 177 if (!container) return;
180 - console.log('[timer] loadTimerView start');
181 178
182 179 // Fetch data independently so one failure doesn't block the rest
183 180 let activeResult = null;
@@ -185,7 +182,6 @@
185 182
186 183 try {
187 184 activeResult = await GoingsOn.api.timeTracking.getActive();
188 - console.log('[timer] getActive result:', activeResult);
189 185 } catch (err) {
190 186 console.error('[timer] getActive failed:', err);
191 187 }
@@ -195,7 +191,6 @@
195 191 GoingsOn.api.tasks.listFiltered({ status: 'Pending', showSnoozed: false, limit: 200 }),
196 192 GoingsOn.api.tasks.listFiltered({ status: 'Started', showSnoozed: false, limit: 200 }),
197 193 ]);
198 - console.log('[timer] listFiltered results — pending:', pendingResp?.tasks?.length, 'started:', startedResp?.tasks?.length);
199 194 const pending = pendingResp?.tasks || [];
200 195 const started = startedResp?.tasks || [];
201 196 // Started first (more likely to be tracked), then pending
@@ -178,14 +178,10 @@
178 178 match state.contacts.create(DESKTOP_USER_ID, new_contact).await {
179 179 Ok(contact) => {
180 180 // Set external source/id for dedup on re-import (must succeed to prevent duplicates)
181 - if let Err(e) = sqlx::query(
182 - "UPDATE contacts SET external_source = ?, external_id = ? WHERE id = ?",
183 - )
184 - .bind("vcf")
185 - .bind(&ext_id)
186 - .bind(contact.id.to_string())
187 - .execute(&state.pool)
188 - .await
181 + if let Err(e) = state
182 + .contacts
183 + .set_external_ref(contact.id, DESKTOP_USER_ID, "vcf", &ext_id)
184 + .await
189 185 {
190 186 tracing::error!(contact = %card.display_name, "Failed to set external source (dedup key lost): {}", e);
191 187 errors.push(format!("{}: failed to set dedup key: {}", card.display_name, e));
@@ -331,16 +327,15 @@
331 327
332 328 match state.events.create(DESKTOP_USER_ID, new_event).await {
333 329 Ok(event) => {
334 - // Set external source/id (file imports are editable, not read-only)
335 - if let Some(ref uid) = parsed.external_id {
336 - let _ = sqlx::query(
337 - "UPDATE events SET external_source = ?, external_id = ? WHERE id = ?",
338 - )
339 - .bind("ics")
340 - .bind(uid)
341 - .bind(event.id.to_string())
342 - .execute(&state.pool)
343 - .await;
330 + // Set external source/id for dedup on re-import (file imports are editable, not read-only)
331 + if let Some(ref uid) = parsed.external_id
332 + && let Err(e) = state
333 + .events
334 + .set_external_ref(event.id, DESKTOP_USER_ID, "ics", uid)
335 + .await
336 + {
337 + tracing::error!(event = %parsed.title, "Failed to set external source (dedup key lost): {}", e);
338 + errors.push(format!("{}: failed to set dedup key: {}", parsed.title, e));
344 339 }
345 340
346 341 imported += 1;
@@ -1852,3 +1852,248 @@
1852 1852 );
1853 1853 }
1854 1854 }
1855 +
1856 + // ── HLC assignment monotonicity ─────────────────────────────────────────────
1857 + //
1858 + // assign_pending_hlcs stamps unpushed local rows lazily; the stamps must sort
1859 + // strictly after each other in stamp order so push and conflict-detection agree
1860 + // on a total order, and each stamp must land in the committed-HLC store as the
1861 + // row's committed clock (so a later older remote edit gates out).
1862 +
1863 + #[tokio::test]
1864 + async fn assign_pending_hlcs_stamps_are_strictly_increasing_and_recorded_committed() {
1865 + use crate::sync_service::hlc::{assign_pending_hlcs, load_committed_hlcs};
1866 +
1867 + let pool = setup_test_db().await;
1868 + let device_id = uuid::Uuid::new_v4();
1869 +
1870 + // Seed a batch of unstamped pending rows in a known id order.
1871 + let row_ids: Vec<String> = (0..6).map(|i| format!("row-{i}")).collect();
1872 + for rid in &row_ids {
1873 + sqlx::query(
1874 + "INSERT INTO sync_changelog (table_name, op, row_id, pushed, hlc_wall, hlc_counter) \
1875 + VALUES ('tasks', 'INSERT', ?, 0, NULL, NULL)",
1876 + )
1877 + .bind(rid)
1878 + .execute(&pool)
1879 + .await
1880 + .unwrap();
1881 + }
1882 +
1883 + assign_pending_hlcs(&pool, device_id).await.unwrap();
1884 +
1885 + // Read the stamps back in the order they were stamped (id ASC).
1886 + let stamped: Vec<(i64, i64, String)> = sqlx::query_as(
1887 + "SELECT hlc_wall, hlc_counter, row_id FROM sync_changelog \
1888 + WHERE pushed = 0 ORDER BY id ASC",
1889 + )
1890 + .fetch_all(&pool)
1891 + .await
1892 + .unwrap();
1893 + assert_eq!(stamped.len(), row_ids.len(), "every pending row is stamped");
1894 +
1895 + // Each stamp is strictly greater than the previous by (wall, counter).
1896 + for w in stamped.windows(2) {
1897 + let (a_wall, a_ctr, _) = &w[0];
1898 + let (b_wall, b_ctr, _) = &w[1];
1899 + assert!(
1900 + (*b_wall, *b_ctr) > (*a_wall, *a_ctr),
1901 + "HLC stamps must be strictly increasing: {:?} then {:?}",
1902 + (a_wall, a_ctr),
1903 + (b_wall, b_ctr),
1904 + );
1905 + }
1906 +
1907 + // Each row's committed HLC equals its stamp (recorded as the max), with this
1908 + // device's node.
1909 + let keys: Vec<(String, String)> = stamped
1910 + .iter()
1911 + .map(|(_, _, r)| ("tasks".to_string(), r.clone()))
1912 + .collect();
1913 + let committed = load_committed_hlcs(&pool, &keys).await.unwrap();
1914 + for (wall, ctr, row_id) in &stamped {
1915 + let hlc = committed
1916 + .get(&("tasks".to_string(), row_id.clone()))
1917 + .copied()
1918 + .unwrap_or_else(|| panic!("no committed HLC for {row_id}"));
1919 + assert_eq!(hlc.wall_ms, *wall);
1920 + assert_eq!(hlc.counter as i64, *ctr);
1921 + assert_eq!(hlc.node, device_id, "committed HLC carries this device's node");
1922 + }
1923 +
1924 + // The persistent clock advanced exactly to the last stamp.
1925 + let (clock_wall, clock_ctr): (i64, i64) =
1926 + sqlx::query_as("SELECT wall_ms, counter FROM hlc_state WHERE id = 1")
1927 + .fetch_one(&pool)
1928 + .await
1929 + .unwrap();
1930 + let last = stamped.last().unwrap();
1931 + assert_eq!(
1932 + (clock_wall, clock_ctr),
1933 + (last.0, last.1),
1934 + "persistent clock advanced to the final stamp",
1935 + );
1936 + }
1937 +
1938 + // ── Apply idempotency + committed-HLC gate backing ──────────────────────────
1939 + //
1940 + // Applying the same upsert twice must be a no-op: no duplicate row, no child
1941 + // cascade, and the committed-HLC store still holds the change's HLC (max-kept),
1942 + // so the CleanChanges gate would drop the already-seen change on a later pull.
1943 +
1944 + #[tokio::test]
1945 + async fn apply_changes_inner_upsert_is_idempotent_and_gate_holds_committed_hlc() {
1946 + use crate::sync_service::hlc::load_committed_hlcs;
1947 + use synckit_client::{ChangeEntry, ChangeOp, Hlc};
1948 +
1949 + let pool = setup_test_db().await;
1950 + let user_id = create_test_user(&pool).await;
1951 + let task_id = uuid::Uuid::new_v4().to_string();
1952 + let annotation_id = uuid::Uuid::new_v4().to_string();
1953 + let now = now_sql();
1954 + let node = uuid::Uuid::new_v4();
1955 + let hlc = Hlc { wall_ms: 5000, counter: 2, node };
1956 +
1957 + let task_data = json!({
1958 + "id": task_id, "project_id": null, "description": "Idempotent",
1959 + "status": "Active", "priority": "Medium", "due": null, "tags": "",
1960 + "urgency": 0.0, "recurrence": "None", "recurrence_rule": null,
1961 + "created_at": now, "user_id": user_id, "recurrence_parent_id": null,
1962 + "source_email_id": null, "snoozed_until": null, "waiting_for_response": 0,
1963 + "waiting_since": null, "expected_response_date": null, "scheduled_start": null,
1964 + "scheduled_duration": null, "is_focus": 0, "focus_set_at": null,
1965 + "contact_id": null, "milestone_id": null, "completed_at": null,
1966 + "estimated_minutes": null, "actual_minutes": null,
1967 + });
1968 +
1969 + let entry = ChangeEntry {
1970 + table: "tasks".to_string(),
1971 + op: ChangeOp::Insert,
1972 + row_id: task_id.clone(),
1973 + timestamp: chrono::Utc::now(),
1974 + hlc,
1975 + data: Some(task_data),
1976 + extra: Default::default(),
1977 + };
1978 +
1979 + let mut conn = pool.acquire().await.unwrap();
1980 + sqlx::query("PRAGMA foreign_keys = ON").execute(&mut *conn).await.unwrap();
1981 +
1982 + // First apply: inserts the task and records its committed HLC.
1983 + pull::apply_changes_inner(&mut conn, vec![entry.clone()]).await.unwrap();
1984 +
1985 + // Attach a child annotation to prove a re-apply does not cascade-delete it.
1986 + apply::apply_upsert(&mut conn, "annotations", &annotation_id, &json!({
1987 + "id": annotation_id, "task_id": task_id, "timestamp": now, "note": "child",
1988 + })).await.unwrap();
1989 +
1990 + // Second apply of the identical change: a no-op, not an error.
1991 + let skipped = pull::apply_changes_inner(&mut conn, vec![entry.clone()]).await.unwrap();
1992 + assert_eq!(skipped, 0, "identical re-apply is not a skip/error");
1993 +
1994 + // Exactly one task row, child annotation intact -- no duplicate, no cascade.
1995 + let task_count: (i64,) = sqlx::query_as("SELECT COUNT(*) FROM tasks WHERE id = ?")
1996 + .bind(&task_id).fetch_one(&pool).await.unwrap();
1997 + assert_eq!(task_count.0, 1, "re-apply must not duplicate the row");
1998 + let ann_count: (i64,) = sqlx::query_as("SELECT COUNT(*) FROM annotations WHERE task_id = ?")
1999 + .bind(&task_id).fetch_one(&pool).await.unwrap();
2000 + assert_eq!(ann_count.0, 1, "child annotation survives the re-apply");
2001 +
2002 + // The committed-HLC store holds exactly the change's HLC (max-kept across both
2003 + // applies). Its HLC is therefore not strictly greater than the committed clock,
2004 + // so SyncKit's CleanChanges gate would drop this already-seen change next pull.
2005 + let key = ("tasks".to_string(), task_id.clone());
2006 + let committed = load_committed_hlcs(&pool, std::slice::from_ref(&key)).await.unwrap();
2007 + let committed_hlc = committed.get(&key).copied().expect("committed HLC recorded");
2008 + assert_eq!(committed_hlc, hlc);
2009 + assert!(
2010 + entry.hlc <= committed_hlc,
2011 + "already-seen HLC is gated out (not newer than committed)",
2012 + );
2013 + }
2014 +
2015 + // ── LWW clock-poison guard ──────────────────────────────────────────────────
2016 + //
2017 + // A remote HLC beyond MAX_HLC_DRIFT_MS in the future is clock-poisoned and, per
2018 + // resolve_lww_at's (honest local, poisoned remote) => KeepLocal rule, cannot win
2019 + // LWW over an honest local write -- the local value survives. resolve_lww_at
2020 + // takes a PulledChange (which is #[non_exhaustive] and not constructible outside
2021 + // synckit-client, so the full resolution runs in synckit-client's own conflict
2022 + // tests); here we pin the load-bearing predicate GO's pull relies on.
2023 +
2024 + #[test]
2025 + fn clock_poison_guard_flags_far_future_remote_but_not_honest_local() {
2026 + use synckit_client::Hlc;
2027 + use synckit_client::conflict::{is_clock_poisoned, MAX_HLC_DRIFT_MS};
2028 +
2029 + let now = chrono::Utc::now();
2030 + let now_ms = now.timestamp_millis();
2031 + let node = uuid::Uuid::new_v4();
2032 +
2033 + // An honest local write at ~now is never flagged.
2034 + let local = Hlc { wall_ms: now_ms, counter: 0, node };
2035 + assert!(!is_clock_poisoned(&local, now), "an at-now HLC must not be poisoned");
2036 +
2037 + // Just inside the drift window is still honest (inter-device skew tolerated).
2038 + let within = Hlc { wall_ms: now_ms + MAX_HLC_DRIFT_MS - 1_000, counter: 0, node };
2039 + assert!(!is_clock_poisoned(&within, now), "skew within the drift cap is allowed");
2040 +
2041 + // A remote HLC far beyond the drift cap is poisoned. It sorts ABOVE the local
2042 + // write, so it would win raw LWW ordering -- but the poison guard makes it lose,
2043 + // so the local value survives.
2044 + let poisoned = Hlc { wall_ms: now_ms + MAX_HLC_DRIFT_MS + 60_000, counter: 0, node };
2045 + assert!(is_clock_poisoned(&poisoned, now), "a far-future remote HLC must be flagged");
2046 + assert!(poisoned > local, "the poisoned HLC would otherwise win raw LWW ordering");
2047 + }
2048 +
2049 + // ── bind_json_value ─────────────────────────────────────────────────────────
2050 + //
2051 + // The apply-side binder: JSON null (and an absent object field, which indexes to
2052 + // Value::Null) must bind SQL NULL; scalars must bind through; a JSON bool binds
2053 + // as an integer.
2054 +
2055 + #[tokio::test]
2056 + async fn bind_json_value_binds_null_absent_and_passthrough_values() {
2057 + let pool = setup_test_db().await;
2058 + let mut conn = pool.acquire().await.unwrap();
2059 +
2060 + sqlx::query("CREATE TABLE bjv_probe (id INTEGER PRIMARY KEY, v)")
2061 + .execute(&mut *conn).await.unwrap();
2062 +
2063 + // Explicit JSON null -> SQL NULL.
2064 + let null_val = serde_json::Value::Null;
2065 + apply::bind_json_value(
2066 + sqlx::query("INSERT INTO bjv_probe (id, v) VALUES (1, ?)"),
2067 + &null_val,
2068 + ).execute(&mut *conn).await.unwrap();
2069 +
2070 + // Absent object field indexes to Value::Null -> SQL NULL.
2071 + let obj = json!({"present": "x"});
2072 + apply::bind_json_value(
2073 + sqlx::query("INSERT INTO bjv_probe (id, v) VALUES (2, ?)"),
2074 + &obj["missing"],
2075 + ).execute(&mut *conn).await.unwrap();
2076 +
2077 + // A normal string binds through unchanged.
2078 + let s = json!("hello");
2079 + apply::bind_json_value(
2080 + sqlx::query("INSERT INTO bjv_probe (id, v) VALUES (3, ?)"),
2081 + &s,
2082 + ).execute(&mut *conn).await.unwrap();
2083 +
2084 + // A JSON bool binds as integer (0/1).
2085 + let b = json!(true);
2086 + apply::bind_json_value(
2087 + sqlx::query("INSERT INTO bjv_probe (id, v) VALUES (4, ?)"),
2088 + &b,
2089 + ).execute(&mut *conn).await.unwrap();
2090 +
2091 + // CAST to TEXT so every affinity decodes uniformly (NULL stays NULL).
2092 + let rows: Vec<(i64, Option<String>)> =
2093 + sqlx::query_as("SELECT id, CAST(v AS TEXT) FROM bjv_probe ORDER BY id")
2094 + .fetch_all(&pool).await.unwrap();
2095 + assert_eq!(rows[0].1, None, "JSON null binds SQL NULL");
2096 + assert_eq!(rows[1].1, None, "absent object field binds SQL NULL");
2097 + assert_eq!(rows[2].1.as_deref(), Some("hello"), "string binds through");
2098 + assert_eq!(rows[3].1.as_deref(), Some("1"), "bool binds as integer 1");
2099 + }
@@ -9,7 +9,11 @@
9 9 // ============ Milestones ============
10 10
11 11 /// Lifecycle status of a milestone.
12 + // `ascii_case_insensitive` so the lowercase `db_value()` form ("open"/"completed")
13 + // round-trips back through `from_str_or_default`; without it a stored "completed"
14 + // failed to parse and silently reverted to `Open` on every read.
12 15 #[derive(Debug, Clone, Serialize, Deserialize, PartialEq, Default, EnumString)]
16 + #[strum(ascii_case_insensitive)]
13 17 pub enum MilestoneStatus {
14 18 /// Milestone is still being worked toward.
15 19 #[strum(serialize = "Open")]
@@ -84,3 +88,23 @@
84 88 pub position: i32,
85 89 pub target_date: Option<chrono::NaiveDate>,
86 90 }
91 +
92 + #[cfg(test)]
93 + mod tests {
94 + use super::*;
95 +
96 + #[test]
97 + fn milestone_status_db_value_round_trips() {
98 + // Regression: the lowercase db_value form must parse back to the same
99 + // variant (was reverting Completed -> Open on read).
100 + for status in [MilestoneStatus::Open, MilestoneStatus::Completed] {
101 + let stored = status.db_value();
102 + assert_eq!(MilestoneStatus::from_str_or_default(stored), status);
103 + }
104 + // The capitalized display form still parses too.
105 + assert_eq!(
106 + MilestoneStatus::from_str_or_default("Completed"),
107 + MilestoneStatus::Completed
108 + );
109 + }
110 + }