feat(kanban): expose redacted sync diagnostics

req: operations/001

req: security/002

req: sync/016

examples/kanban/static/command-log.js

@@ -51,6 +51,7 @@ function migrateCommandLog(request, oldVersion) {
         schemaVersion: COMMAND_SCHEMA,
         targetColumn: command.targetColumn || "done",
         accountPartition: command.accountPartition || "demo:demo",
+        queuedAt: Number.isSafeInteger(command.queuedAt) ? command.queuedAt : Date.now(),
       });
     }
     meta.put({ from: oldVersion, to: DATABASE_VERSION, migrated: legacy.length }, MIGRATION_KEY);
@@ -139,6 +140,7 @@ async function appendReorder(database, accountPartition, wire) {
     actor,
     session: stableSession(),
     causal,
+    queuedAt: Date.now(),
     kind: "reorder_card",
     cardId: String(wire[2] || "1"),
     targetColumn: "done",
@@ -199,6 +201,7 @@ function validate(command) {
   if (typeof command.actor !== "string" || !command.actor) invalidCommand(command, "actor");
   if (typeof command.session !== "string" || !command.session) invalidCommand(command, "session");
   if (!Number.isSafeInteger(command.causal) || command.causal < 1) invalidCommand(command, "causal");
+  if (!Number.isSafeInteger(command.queuedAt) || command.queuedAt < 0) invalidCommand(command, "queuedAt");
   if (command.id !== `${command.actor}:${command.causal}`) invalidCommand(command, "id");
   if (command.kind !== "reorder_card") invalidCommand(command, "kind");
   if (typeof command.cardId !== "string" || !command.cardId) invalidCommand(command, "cardId");

examples/kanban/static/sync.js

@@ -21,6 +21,9 @@ let uploadsThisRun = 0;
 let uploadedTotal = 0;
 let inFlightUploads = 0;
 let maxObservedInFlight = 0;
+let acknowledgementStartedAt;
+let conflictCount = 0;
+let rejectionCount = 0;
 let activeConflict;
 let manualRetryCommand;
 let stopped = false;
@@ -74,6 +77,7 @@ function migrateCommandLog(request, oldVersion) {
         schemaVersion: COMMAND_SCHEMA,
         targetColumn: command.targetColumn || "done",
         accountPartition: command.accountPartition || "demo:demo",
+        queuedAt: Number.isSafeInteger(command.queuedAt) ? command.queuedAt : Date.now(),
       });
     }
     meta.put({ from: oldVersion, to: DATABASE_VERSION, migrated: legacy.length }, MIGRATION_KEY);
@@ -158,6 +162,34 @@ function setPhase(phase, message) {
   root.querySelector('[role="status"]').textContent = message;
 }
 
+function ageBucket(milliseconds) {
+  if (milliseconds < 1000) return "lt-1s";
+  if (milliseconds < 10000) return "1s-10s";
+  if (milliseconds < 60000) return "10s-1m";
+  return "gte-1m";
+}
+
+function latencyBucket(milliseconds) {
+  if (milliseconds < 50) return "lt-50ms";
+  if (milliseconds < 250) return "50ms-250ms";
+  if (milliseconds < 1000) return "250ms-1s";
+  return "gte-1s";
+}
+
+function publishDiagnostics(commands) {
+  const queued = Array.isArray(commands) ? commands : [];
+  const oldest = queued.reduce((value, command) => {
+    return Number.isSafeInteger(command.queuedAt) ? Math.min(value, command.queuedAt) : value;
+  }, Date.now());
+  root.setAttribute("data-sync-diag-queue-count", String(queued.length));
+  root.setAttribute("data-sync-diag-oldest-age-bucket", queued.length === 0 ? "empty" : ageBucket(Date.now() - oldest));
+  root.setAttribute("data-sync-diag-cursor", root.getAttribute("data-sync-ack-sequence") || "0");
+  root.setAttribute("data-sync-diag-conflicts", String(conflictCount));
+  root.setAttribute("data-sync-diag-rejections", String(rejectionCount));
+  const diagnostics = root.querySelector("[data-sync-diagnostics]");
+  diagnostics.textContent = `Queue ${queued.length}; oldest ${root.getAttribute("data-sync-diag-oldest-age-bucket")}; cursor ${root.getAttribute("data-sync-diag-cursor")}; acknowledgement ${root.getAttribute("data-sync-diag-ack-latency-bucket") || "none"}; conflicts ${conflictCount}; rejections ${rejectionCount}.`;
+}
+
 function validatePending(command) {
   if (!command || command.schemaVersion !== COMMAND_SCHEMA || command.accountPartition !== accountPartition || command.kind !== "reorder_card" || typeof command.id !== "string" || !command.id || typeof command.cardId !== "string" || !command.cardId || command.targetColumn !== "done") {
     throw new Error("invalid pending command");
@@ -301,6 +333,7 @@ function finishUpload() {
 async function continuePendingWork() {
   const commands = await pendingCommands(database);
   root.setAttribute("data-sync-pending-count", String(commands.length));
+  publishDiagnostics(commands);
   setExportAvailable(commands.length > 0);
   if (commands.length === 0) return;
   if (uploadsThisRun >= uploadLimit) {
@@ -340,6 +373,7 @@ async function synchronize(command) {
     }
     setOnline(true);
     root.setAttribute("data-sync-upload-sequence", String(acknowledgement.serverSequence));
+    acknowledgementStartedAt = performance.now();
     setPhase("awaiting-ack", `Command ${command.id} uploaded; awaiting canonical acknowledgement.`);
 
     const reconnect = command.session || command.actor || "kanban";
@@ -371,9 +405,11 @@ async function synchronize(command) {
       root.setAttribute("data-sync-pending-count", String(pendingAfterAck));
       setExportAvailable(pendingAfterAck > 0);
       root.setAttribute("data-sync-ack-sequence", String(canonical.serverSequence));
-      root.setAttribute("data-sync-ack-command-id", canonical.commandId);
+      root.setAttribute("data-sync-diag-cursor", String(canonical.serverSequence));
+      root.setAttribute("data-sync-diag-ack-latency-bucket", latencyBucket(performance.now() - acknowledgementStartedAt));
       root.setAttribute("data-sync-canonical-column", canonical.canonicalColumn);
-      setPhase("acknowledged", `Command ${command.id} acknowledged in ${canonical.canonicalColumn}.`);
+      publishDiagnostics(await pendingCommands(database));
+      setPhase("acknowledged", `Queued change acknowledged in ${canonical.canonicalColumn}.`);
       root.dispatchEvent(new CustomEvent("kanban:sync-acknowledged", { detail: canonical }));
       synchronizing = false;
       clearTimeout(leaseTimer);
@@ -410,7 +446,9 @@ async function synchronize(command) {
         setPhase("rebased", `Canonical snapshot ${snapshot.serverSequence} already satisfies ${command.id}; committed and removed the pending command.`);
         root.dispatchEvent(new CustomEvent("kanban:sync-rebased", { detail: { snapshot, command, decision } }));
       } else {
+        conflictCount += 1;
         activeConflict = { command, snapshot, decision };
+        publishDiagnostics(await pendingCommands(database));
         setConflictResolutionAvailable(true);
         setPhase("conflicted", `Canonical snapshot ${snapshot.serverSequence} conflicts with ${command.id} (${decision.reason}); the pending command remains queued.`);
         root.dispatchEvent(new CustomEvent("kanban:sync-conflicted", { detail: { snapshot, command, decision } }));
@@ -431,6 +469,8 @@ async function synchronize(command) {
       root.setAttribute("data-sync-error-status", String(error.status));
       const remaining = await pendingCommands(database);
       setManualRetryAvailable(false);
+      rejectionCount += 1;
+      publishDiagnostics(remaining);
       if (command.conflictResolution === "keep-local-change") {
         manualRetryCommand = undefined;
         setConflictResolutionAvailable(true);
@@ -507,6 +547,8 @@ async function start() {
   root.setAttribute("data-sync-in-flight", "0");
   root.setAttribute("data-sync-max-observed-in-flight", "0");
   root.setAttribute("data-sync-pending-count", String(commands.length));
+  publishDiagnostics(commands);
+  root.setAttribute("data-sync-diag-ack-latency-bucket", "none");
   setExportAvailable(commands.length > 0);
   setConflictResolutionAvailable(false);
   setManualRetryAvailable(false);

examples/kanban/templates/sync_shell.heml

@@ -9,6 +9,7 @@
   <section data-kanban-sync data-sync-version="1" data-sync-upload-limit="2" aria-labelledby="sync-title">
     <h2 id="sync-title">Sync status</h2>
     <p role="status" aria-live="polite">Waiting for pending commands.</p>
+    <output data-sync-diagnostics aria-label="Redacted sync diagnostics"></output>
     <button type="button" data-sync-retry>Retry sync now</button>
     <button type="button" data-sync-export disabled>Export this account's queue</button>
     <button type="button" data-sync-use-canonical disabled>Use canonical state and continue</button>

examples/kanban/tests/browser_e2e.rs

@@ -290,7 +290,7 @@ async fn pending_local_command_uploads_with_bounded_retry_and_is_removed_on_ack(
         assert_eq!(proof["uploadSequence"], "1");
         assert_eq!(proof["ackSequence"], "1");
         assert_eq!(proof["canonicalColumn"], "done");
-        assert_eq!(proof["status"], "Command sync-actor:1 acknowledged in done.");
+        assert_eq!(proof["status"], "Queued change acknowledged in done.");
         assert!(proof["error"].is_null());
 
         let queue_count = driver
@@ -580,14 +580,13 @@ async fn account_partition_hides_replay_and_export_until_owner_returns() -> WebD
         .await?;
         let authorized = driver
             .execute(
-                "const root = document.querySelector('[data-kanban-sync]'); return { sequence: root.getAttribute('data-sync-ack-sequence'), command: root.getAttribute('data-sync-ack-command-id'), column: root.getAttribute('data-sync-canonical-column'), pending: root.getAttribute('data-sync-pending-count') }",
+                "const root = document.querySelector('[data-kanban-sync]'); return { sequence: root.getAttribute('data-sync-ack-sequence'), column: root.getAttribute('data-sync-canonical-column'), pending: root.getAttribute('data-sync-pending-count') }",
                 Vec::new(),
             )
             .await?
             .json()
             .clone();
         assert_eq!(authorized["sequence"], "1");
-        assert_eq!(authorized["command"], "auth:1");
         assert_eq!(authorized["column"], "done");
         assert_eq!(authorized["pending"], "0");
         assert_eq!(command_count(&driver).await?, 0);
@@ -1106,7 +1105,7 @@ async fn upload_backpressure_keeps_pending_work_visible_and_recoverable() -> Web
         assert_eq!(recovered["total"], "3");
         assert_eq!(recovered["maxInFlight"], "1");
         assert_eq!(recovered["sequence"], "3");
-        assert_eq!(recovered["status"], "Command pressure:3 acknowledged in done.");
+        assert_eq!(recovered["status"], "Queued change acknowledged in done.");
         assert_eq!(command_count(&driver).await?, 0);
         Ok(())
     }
@@ -1242,7 +1241,7 @@ async fn two_tabs_coordinate_single_uploader_and_takeover_without_duplicate_appl
         assert_eq!(takeover["attempts"], "1");
         assert_eq!(takeover["pending"], "0");
         assert_eq!(takeover["sequence"], "1");
-        assert_eq!(takeover["status"], "Command tabs:1 acknowledged in done.");
+        assert_eq!(takeover["status"], "Queued change acknowledged in done.");
         assert_eq!(command_count(&driver).await?, 0);
 
         driver
@@ -1390,7 +1389,7 @@ async fn exhausted_offline_retries_keep_command_until_later_reconnect() -> WebDr
         assert_eq!(converged["attempts"], "1");
         assert_eq!(converged["sequence"], "1");
         assert_eq!(converged["column"], "done");
-        assert_eq!(converged["status"], "Command offline-actor:1 acknowledged in done.");
+        assert_eq!(converged["status"], "Queued change acknowledged in done.");
         assert!(converged["error"].is_null());
         assert_eq!(command_count(&driver).await?, 0);
 
@@ -1605,7 +1604,7 @@ async fn missing_history_rebase_and_user_conflict_resolution_preserve_suffix() -
         .await?;
         let conflicted = driver
             .execute(
-                "const root = document.querySelector('[data-kanban-sync]'); return { phase: root.getAttribute('data-sync-phase'), uploadSequence: root.getAttribute('data-sync-upload-sequence'), snapshotSequence: root.getAttribute('data-sync-snapshot-sequence'), pending: root.getAttribute('data-sync-pending-count'), rebasePending: root.getAttribute('data-sync-rebase-pending-count'), decision: root.getAttribute('data-sync-rebase-decision'), reason: root.getAttribute('data-sync-rebase-reason'), canonicalColumn: root.getAttribute('data-sync-canonical-column'), resolutionDisabled: root.querySelector('[data-sync-use-canonical]').disabled, status: root.querySelector('[role=status]').textContent, error: root.getAttribute('data-sync-error') }",
+                "const root = document.querySelector('[data-kanban-sync]'); return { phase: root.getAttribute('data-sync-phase'), uploadSequence: root.getAttribute('data-sync-upload-sequence'), snapshotSequence: root.getAttribute('data-sync-snapshot-sequence'), pending: root.getAttribute('data-sync-pending-count'), rebasePending: root.getAttribute('data-sync-rebase-pending-count'), decision: root.getAttribute('data-sync-rebase-decision'), reason: root.getAttribute('data-sync-rebase-reason'), canonicalColumn: root.getAttribute('data-sync-canonical-column'), resolutionDisabled: root.querySelector('[data-sync-use-canonical]').disabled, diagnosticConflicts: root.getAttribute('data-sync-diag-conflicts'), diagnosticVisible: root.querySelector('[data-sync-diagnostics]').textContent, status: root.querySelector('[role=status]').textContent, error: root.getAttribute('data-sync-error') }",
                 Vec::new(),
             )
             .await?
@@ -1620,6 +1619,8 @@ async fn missing_history_rebase_and_user_conflict_resolution_preserve_suffix() -
         assert_eq!(conflicted["reason"], "canonical-state-diverged");
         assert_eq!(conflicted["canonicalColumn"], "doing");
         assert_eq!(conflicted["resolutionDisabled"], false);
+        assert_eq!(conflicted["diagnosticConflicts"], "1");
+        assert!(conflicted["diagnosticVisible"].as_str().unwrap().ends_with("conflicts 1; rejections 0."));
         assert_eq!(
             conflicted["status"],
             "Canonical snapshot 4 conflicts with history:3 (canonical-state-diverged); the pending command remains queued."
@@ -1704,6 +1705,132 @@ async fn missing_history_rebase_and_user_conflict_resolution_preserve_suffix() -
     result.and(quit)
 }
 
+#[tokio::test]
+async fn redacted_sync_diagnostics_are_bounded_and_leak_no_sensitive_material(
+) -> WebDriverResult<()> {
+    // test req: operations/001 req: security/002 req: sync/016 req: sync/021
+    let app_port = available_port();
+    let app_addr = format!("127.0.0.1:{app_port}");
+    let mut app_command = Command::new(env!("CARGO_BIN_EXE_hemx-kanban-example"));
+    app_command
+        .env("HEMX_KANBAN_ADDR", &app_addr)
+        .env("HEMX_KANBAN_SYNC_FAILURES", "3");
+    let _app = TestProcess::start(app_command, "hemx-kanban", &app_addr, STARTUP_TIMEOUT)
+        .expect("start ready hemx-kanban");
+
+    let webdriver_port = available_port();
+    let webdriver_addr = format!("127.0.0.1:{webdriver_port}");
+    let mut webdriver = Command::new("geckodriver");
+    webdriver.arg("--port").arg(webdriver_port.to_string());
+    let _webdriver = TestProcess::start(webdriver, "geckodriver", &webdriver_addr, STARTUP_TIMEOUT)
+        .expect("start ready geckodriver");
+    let mut caps = DesiredCapabilities::firefox();
+    caps.set_headless()?;
+    let driver = WebDriver::new(&format!("http://{webdriver_addr}"), caps).await?;
+
+    let result = async {
+        driver.goto(&format!("http://{app_addr}/")).await?;
+        let seeded = driver
+            .execute_async(
+                r#"
+                const done = arguments[arguments.length - 1];
+                const open = indexedDB.open('hemx-kanban-v1', 3);
+                open.onupgradeneeded = () => {
+                  const database = open.result;
+                  const commands = database.createObjectStore('commands', { keyPath: 'id' });
+                  commands.createIndex('byAccountPartition', 'accountPartition');
+                  database.createObjectStore('meta');
+                };
+                open.onsuccess = () => {
+                  const tx = open.result.transaction('commands', 'readwrite');
+                  tx.objectStore('commands').add({
+                    id: 'diag-secret-command', schemaVersion: 2, accountPartition: 'demo:demo',
+                    actor: 'private-actor', session: 'super-secret-session-token', causal: 1,
+                    queuedAt: Date.now() - 15000, kind: 'reorder_card', cardId: '1', targetColumn: 'done',
+                    eventKind: 'click', key: null, privatePayload: 'customer-secret-payload',
+                  });
+                  tx.oncomplete = () => done({ seeded: true });
+                  tx.onabort = () => done({ error: tx.error && tx.error.name });
+                };
+                "#,
+                Vec::new(),
+            )
+            .await?
+            .json()
+            .clone();
+        assert_eq!(seeded["seeded"], true);
+
+        driver.goto(&format!("http://{app_addr}/sync-demo")).await?;
+        wait_until(
+            &driver,
+            "const root = document.querySelector('[data-kanban-sync]'); return root?.getAttribute('data-sync-phase') === 'offline' && root?.getAttribute('data-sync-pending-count') === '1'",
+        )
+        .await?;
+        let queued = driver
+            .execute(
+                "const root = document.querySelector('[data-kanban-sync]'); const names = ['data-sync-diag-queue-count','data-sync-diag-oldest-age-bucket','data-sync-diag-cursor','data-sync-diag-ack-latency-bucket','data-sync-diag-conflicts','data-sync-diag-rejections']; const diagnostics = Object.fromEntries(names.map((name) => [name, root.getAttribute(name)])); return { diagnostics, visible: root.querySelector('[data-sync-diagnostics]').textContent }",
+                Vec::new(),
+            )
+            .await?
+            .json()
+            .clone();
+        assert_eq!(
+            queued["diagnostics"],
+            serde_json::json!({
+                "data-sync-diag-queue-count": "1",
+                "data-sync-diag-oldest-age-bucket": "10s-1m",
+                "data-sync-diag-cursor": "0",
+                "data-sync-diag-ack-latency-bucket": "none",
+                "data-sync-diag-conflicts": "0",
+                "data-sync-diag-rejections": "0"
+            })
+        );
+        assert!(queued["visible"].as_str().unwrap().contains("Queue 1; oldest 10s-1m; cursor 0; acknowledgement none"));
+
+        driver.find(By::Css("[data-sync-retry]")).await?.click().await?;
+        wait_until(
+            &driver,
+            "const root = document.querySelector('[data-kanban-sync]'); return root?.getAttribute('data-sync-phase') === 'acknowledged' && root?.getAttribute('data-sync-pending-count') === '0'",
+        )
+        .await?;
+        let proof = driver
+            .execute(
+                "const root = document.querySelector('[data-kanban-sync]'); const names = ['data-sync-diag-queue-count','data-sync-diag-oldest-age-bucket','data-sync-diag-cursor','data-sync-diag-ack-latency-bucket','data-sync-diag-conflicts','data-sync-diag-rejections']; const diagnostics = Object.fromEntries(names.map((name) => [name, root.getAttribute(name)])); return { diagnostics, visible: root.querySelector('[data-sync-diagnostics]').textContent, rootHtml: root.outerHTML, cookies: document.cookie }",
+                Vec::new(),
+            )
+            .await?
+            .json()
+            .clone();
+        assert_eq!(proof["diagnostics"]["data-sync-diag-queue-count"], "0");
+        assert_eq!(proof["diagnostics"]["data-sync-diag-oldest-age-bucket"], "empty");
+        assert_eq!(proof["diagnostics"]["data-sync-diag-cursor"], "1");
+        assert_eq!(proof["diagnostics"]["data-sync-diag-conflicts"], "0");
+        assert_eq!(proof["diagnostics"]["data-sync-diag-rejections"], "0");
+        assert!(matches!(
+            proof["diagnostics"]["data-sync-diag-ack-latency-bucket"].as_str(),
+            Some("lt-50ms" | "50ms-250ms" | "250ms-1s" | "gte-1s")
+        ));
+        let visible = proof["visible"].as_str().unwrap();
+        assert!(visible.contains("Queue 0; oldest empty; cursor 1; acknowledgement"));
+        assert!(visible.len() < 120);
+        let exposed = format!("{}\n{}\n{}\n{}", queued["visible"], proof["visible"], proof["rootHtml"], proof["cookies"]);
+        for secret in [
+            "diag-secret-command",
+            "private-actor",
+            "super-secret-session-token",
+            "customer-secret-payload",
+            "cardId",
+            "privatePayload",
+        ] {
+            assert!(!exposed.contains(secret), "diagnostics leaked {secret}: {exposed}");
+        }
+        Ok(())
+    }
+    .await;
+    let quit = driver.quit().await;
+    result.and(quit)
+}
+
 #[tokio::test]
 async fn keep_local_retry_preserves_conflicted_command_and_suffix_order() -> WebDriverResult<()> {
     // test req: sync/009 req: sync/010 req: sync/011 req: sync/016
@@ -1841,6 +1968,8 @@ async fn keep_local_retry_preserves_conflicted_command_and_suffix_order() -> Web
                     resolution: root.getAttribute('data-sync-conflict-resolution'),
                     resolutionDisabled: root.querySelector('[data-sync-keep-local]').disabled,
                     pending: root.getAttribute('data-sync-pending-count'),
+                    diagnosticRejections: root.getAttribute('data-sync-diag-rejections'),
+                    diagnosticVisible: root.querySelector('[data-sync-diagnostics]').textContent,
                     rejections: window.__keepRejections,
                     commands: request.result.sort((left, right) => left.causal - right.causal).map(({ id, causal, cardId }) => ({ id, causal, cardId })),
                   });
@@ -1854,6 +1983,8 @@ async fn keep_local_retry_preserves_conflicted_command_and_suffix_order() -> Web
         assert_eq!(rejected["resolution"], "keep-local-rejected");
         assert_eq!(rejected["resolutionDisabled"], false);
         assert_eq!(rejected["pending"], "2");
+        assert_eq!(rejected["diagnosticRejections"], "1");
+        assert!(rejected["diagnosticVisible"].as_str().unwrap().ends_with("conflicts 1; rejections 1."));
         assert_eq!(rejected["rejections"], 1);
         assert_eq!(
             rejected["commands"],