Log timing info for document load

src/components/App.tsx

@@ -11,6 +11,7 @@ import Editor from './Editor';
 import { HashRouter, Route, useNavigate } from '@solidjs/router';
 import { defaultVault } from '../sync';
 import { getDocsMap } from '../vault';
+import DebugView from './Debug';
 
 interface NavbarProps {
   fileId: Accessor<string | null>;
@@ -67,6 +68,7 @@ function App() {
     <HashRouter root={Layout}>
       <Route path="" component={Chooser} />
       <Route path="doc/:id" component={Editor} />
+      <Route path="debug" component={DebugView} />
     </HashRouter>
   );
 }

src/components/Debug.tsx

@@ -0,0 +1,13 @@
+import { createSignal, For } from 'solid-js';
+
+const [getDebugLogs, setDebugLogs] = createSignal<string[]>([]);
+
+export function debugLog(message: string, ...args: any[]) {
+  const components = [message, ...args.map((x) => JSON.stringify(x))];
+  const line = components.join(' ');
+  setDebugLogs([...getDebugLogs(), line]);
+}
+
+export default function DebugView() {
+  return <For each={getDebugLogs()}>{(logLine) => <p>{logLine}</p>}</For>;
+}

src/persistence.ts

@@ -60,6 +60,7 @@ async function initialLoad(id: string): Promise<State> {
   };
 }
 
+// @ts-ignore
 class BufferedWriter {
   private deltaBuffer: Uint8Array[];
   private docId: string;

src/sync.ts

@@ -3,6 +3,7 @@ import * as Y from 'yjs';
 import { openDB, type DBSchema } from 'idb';
 import { assert, generateId } from './util';
 import { getDocsMap, getVaultMap, type DocMap } from './vault';
+import { debugLog } from './components/Debug';
 
 const DB_NAME = 'synced-docs';
 export const LOCAL_DELTA_STORE = 'local-updates';
@@ -59,16 +60,28 @@ export class LocalDocument {
 
   public static async load(id: string): Promise<LocalDocument> {
     // Build Y.Doc from records on disk
+    const startMs = performance.now();
     const updates: Uint8Array[] = await docsDb.getAll(
       LOCAL_DELTA_STORE,
       IDBKeyRange.bound([id, -Infinity], [id, Infinity])
     );
+    const loadedMs = performance.now();
+    const mergedUpdate = Y.mergeUpdates(updates);
+    const mergedMs = performance.now();
     const ydoc = new Y.Doc();
-    Y.applyUpdate(ydoc, Y.mergeUpdates(updates));
+    Y.applyUpdate(ydoc, mergedUpdate);
+    const appliedMs = performance.now();
 
     // Build LocalDocument instance
     const result = new LocalDocument(id, ydoc);
     result.totalUpdates = updates.length;
+
+    // Emit debug timings
+    const timings = [loadedMs, mergedMs, appliedMs].map((x) => x - startMs);
+    debugLog(
+      `Loaded ${updates.length} updates for doc ${id}, load/merge/apply timings in ms`,
+      timings
+    );
     return result;
   }