diff --git a/index.js b/index.js index 254685b..569a94c 100644 --- a/index.js +++ b/index.js @@ -9220,10 +9220,19 @@ function applyIndexedDbSnapshotToRuntime( return result; } let graphFromSnapshot = null; + let hydrateDiagnostics = null; try { const hydrateStartedAt = readLoadDiagnosticsNow(); graphFromSnapshot = buildGraphFromSnapshot(snapshot, { chatId: normalizedChatId, + onDiagnostics(snapshotValue) { + hydrateDiagnostics = + snapshotValue && + typeof snapshotValue === "object" && + !Array.isArray(snapshotValue) + ? snapshotValue + : null; + }, }); hydrateMs = readLoadDiagnosticsNow() - hydrateStartedAt; } catch (error) { @@ -9275,6 +9284,18 @@ function applyIndexedDbSnapshotToRuntime( reason: failureReason, revision, hydrateMs: normalizeLoadDiagnosticsMs(hydrateMs), + hydrateNodesMs: normalizeLoadDiagnosticsMs(hydrateDiagnostics?.nodesMs), + hydrateEdgesMs: normalizeLoadDiagnosticsMs(hydrateDiagnostics?.edgesMs), + hydrateRuntimeMetaMs: normalizeLoadDiagnosticsMs( + hydrateDiagnostics?.runtimeMetaMs, + ), + hydrateStateMs: normalizeLoadDiagnosticsMs(hydrateDiagnostics?.stateMs), + hydrateNormalizeMs: normalizeLoadDiagnosticsMs( + hydrateDiagnostics?.normalizeMs, + ), + hydrateIntegrityMs: normalizeLoadDiagnosticsMs( + hydrateDiagnostics?.integrityMs, + ), error: error?.message || String(error), integrityReasons: Array.isArray(error?.reasons) ? [...error.reasons] : [], }); @@ -9391,6 +9412,18 @@ function applyIndexedDbSnapshotToRuntime( reason: result.reason, revision, hydrateMs: normalizeLoadDiagnosticsMs(hydrateMs), + hydrateNodesMs: normalizeLoadDiagnosticsMs(hydrateDiagnostics?.nodesMs), + hydrateEdgesMs: normalizeLoadDiagnosticsMs(hydrateDiagnostics?.edgesMs), + hydrateRuntimeMetaMs: normalizeLoadDiagnosticsMs( + hydrateDiagnostics?.runtimeMetaMs, + ), + hydrateStateMs: normalizeLoadDiagnosticsMs(hydrateDiagnostics?.stateMs), + hydrateNormalizeMs: normalizeLoadDiagnosticsMs( + hydrateDiagnostics?.normalizeMs, + ), + hydrateIntegrityMs: normalizeLoadDiagnosticsMs( + hydrateDiagnostics?.integrityMs, + ), applyRuntimeMs: normalizeLoadDiagnosticsMs( readLoadDiagnosticsNow() - applyRuntimeStartedAt, ), @@ -9422,6 +9455,7 @@ async function loadGraphFromIndexedDb( totalMs: normalizeLoadDiagnosticsMs(readLoadDiagnosticsNow() - loadStartedAt), }); let exportSnapshotMs = 0; + let exportProbeMs = 0; let preApplyMs = 0; let exportSnapshotSource = ""; if (!normalizedChatId) { @@ -9582,34 +9616,49 @@ async function loadGraphFromIndexedDb( }); } let snapshot = null; + let inspectionSnapshot = null; if (identityRecoveryResult?.snapshot) { snapshot = identityRecoveryResult.snapshot; + inspectionSnapshot = snapshot; exportSnapshotSource = "identity-recovery"; } else if (localStoreMigrationResult?.snapshot) { snapshot = localStoreMigrationResult.snapshot; + inspectionSnapshot = snapshot; exportSnapshotSource = "local-store-migration"; } else if (migrationResult?.snapshot) { snapshot = migrationResult.snapshot; + inspectionSnapshot = snapshot; exportSnapshotSource = "legacy-migration"; } else { - const exportStartedAt = readLoadDiagnosticsNow(); - snapshot = await db.exportSnapshot({ includeTombstones: false }); - exportSnapshotMs = readLoadDiagnosticsNow() - exportStartedAt; - exportSnapshotSource = "indexeddb-export"; + if (typeof db.exportSnapshotProbe === "function") { + const probeStartedAt = readLoadDiagnosticsNow(); + inspectionSnapshot = await db.exportSnapshotProbe({ includeTombstones: false }); + exportProbeMs = readLoadDiagnosticsNow() - probeStartedAt; + exportSnapshotSource = "indexeddb-probe"; + } + if (!inspectionSnapshot) { + const exportStartedAt = readLoadDiagnosticsNow(); + snapshot = await db.exportSnapshot({ includeTombstones: false }); + exportSnapshotMs = readLoadDiagnosticsNow() - exportStartedAt; + inspectionSnapshot = snapshot; + exportSnapshotSource = "indexeddb-export"; + } } const shadowSnapshot = resolveCompatibleGraphShadowSnapshot( resolveCurrentChatIdentity(getContext()), ); - cacheIndexedDbSnapshot(normalizedChatId, snapshot); - const snapshotStore = resolveSnapshotGraphStorePresentation(snapshot, localStore); + const snapshotStore = resolveSnapshotGraphStorePresentation( + inspectionSnapshot || snapshot, + localStore, + ); const commitMarkerMismatch = detectIndexedDbSnapshotCommitMarkerMismatch( - snapshot, + inspectionSnapshot, commitMarker, ); let commitMarkerDiagnostic = null; - if (!isIndexedDbSnapshotMeaningful(snapshot)) { + if (!isIndexedDbSnapshotMeaningful(inspectionSnapshot)) { if (commitMarkerMismatch.mismatched) { commitMarkerDiagnostic = recordPersistMismatchDiagnostic( commitMarkerMismatch, @@ -9709,9 +9758,9 @@ async function loadGraphFromIndexedDb( } const snapshotRevision = normalizeIndexedDbRevision( - snapshot?.meta?.revision, + inspectionSnapshot?.meta?.revision, ); - const snapshotIntegrity = String(snapshot?.meta?.integrity || "").trim(); + const snapshotIntegrity = String(inspectionSnapshot?.meta?.integrity || "").trim(); const shadowDecision = shouldPreferShadowSnapshotOverOfficial( createShadowComparisonGraph({ chatId: normalizedChatId, @@ -9806,6 +9855,68 @@ async function loadGraphFromIndexedDb( }; } + const staleDecision = detectStaleIndexedDbSnapshotAgainstRuntime( + normalizedChatId, + inspectionSnapshot, + ); + if (staleDecision.stale) { + const result = { + success: false, + loaded: false, + reason: `${snapshotStore.reasonPrefix}-stale-runtime`, + chatId: normalizedChatId, + attemptIndex, + revision: snapshotRevision, + staleDetail: cloneRuntimeDebugValue(staleDecision, null), + }; + updateGraphPersistenceState({ + storagePrimary: snapshotStore.storagePrimary, + storageMode: snapshotStore.storageMode, + indexedDbLastError: "", + dualWriteLastResult: { + action: "load", + source: String(source || snapshotStore.reasonPrefix), + success: false, + rejected: true, + reason: result.reason, + revision: snapshotRevision, + staleDetail: cloneRuntimeDebugValue(staleDecision, null), + at: Date.now(), + }, + }); + recordLoadDiagnostics({ + success: false, + loaded: false, + reason: result.reason, + revision: snapshotRevision, + storagePrimary: snapshotStore.storagePrimary, + storageMode: snapshotStore.storageMode, + exportSnapshotSource: exportSnapshotSource || "snapshot-probe", + exportProbeMs: normalizeLoadDiagnosticsMs(exportProbeMs), + exportSnapshotMs: normalizeLoadDiagnosticsMs(exportSnapshotMs), + preApplyMs: normalizeLoadDiagnosticsMs(readLoadDiagnosticsNow() - loadStartedAt), + preApplyOtherMs: normalizeLoadDiagnosticsMs( + Math.max( + 0, + readLoadDiagnosticsNow() - loadStartedAt - exportSnapshotMs - exportProbeMs, + ), + ), + staleDetail: cloneRuntimeDebugValue(staleDecision, null), + }); + return result; + } + + if (!snapshot) { + const exportStartedAt = readLoadDiagnosticsNow(); + snapshot = await db.exportSnapshot({ includeTombstones: false }); + exportSnapshotMs += readLoadDiagnosticsNow() - exportStartedAt; + exportSnapshotSource = + exportSnapshotSource === "indexeddb-probe" + ? "indexeddb-probe+indexeddb-export" + : exportSnapshotSource || "indexeddb-export"; + } + cacheIndexedDbSnapshot(normalizedChatId, snapshot); + preApplyMs = readLoadDiagnosticsNow() - loadStartedAt; const applyInvokeStartedAt = readLoadDiagnosticsNow(); const loadResult = applyIndexedDbSnapshotToRuntime(normalizedChatId, snapshot, { @@ -9835,10 +9946,11 @@ async function loadGraphFromIndexedDb( storageMode: snapshotStore.storageMode, commitMarkerMismatched: commitMarkerMismatch.mismatched === true, exportSnapshotSource: exportSnapshotSource || "snapshot-prepared", + exportProbeMs: normalizeLoadDiagnosticsMs(exportProbeMs), exportSnapshotMs: normalizeLoadDiagnosticsMs(exportSnapshotMs), preApplyMs: normalizeLoadDiagnosticsMs(preApplyMs), preApplyOtherMs: normalizeLoadDiagnosticsMs( - Math.max(0, preApplyMs - exportSnapshotMs), + Math.max(0, preApplyMs - exportSnapshotMs - exportProbeMs), ), applyInvokeMs: normalizeLoadDiagnosticsMs(applyInvokeMs), untrackedMs: normalizeLoadDiagnosticsMs( @@ -9876,6 +9988,7 @@ async function loadGraphFromIndexedDb( storageMode: localStore.storageMode, error: error?.message || String(error), exportSnapshotSource: exportSnapshotSource || "unknown", + exportProbeMs: normalizeLoadDiagnosticsMs(exportProbeMs), exportSnapshotMs: normalizeLoadDiagnosticsMs(exportSnapshotMs), preApplyMs: normalizeLoadDiagnosticsMs( preApplyMs || (readLoadDiagnosticsNow() - loadStartedAt), @@ -9884,7 +9997,8 @@ async function loadGraphFromIndexedDb( Math.max( 0, (preApplyMs || (readLoadDiagnosticsNow() - loadStartedAt)) - - exportSnapshotMs, + exportSnapshotMs - + exportProbeMs, ), ), }); @@ -10703,6 +10817,8 @@ async function persistGraphToConfiguredDurableTier( reason, lastProcessedAssistantFloor = null, persistDelta = null, + graphSnapshot = null, + persistSnapshot = null, chatStateTarget = null, graphDetached = false, } = {}, @@ -10796,6 +10912,8 @@ async function persistGraphToConfiguredDurableTier( persistRole: "cache-mirror", scheduleCloudUpload: false, persistDelta, + graphSnapshot, + persistSnapshot, graphDetached, }); } @@ -10826,6 +10944,8 @@ async function persistGraphToConfiguredDurableTier( revision, reason, persistDelta, + graphSnapshot, + persistSnapshot, }); if (indexedDbResult?.saved) { persistGraphCommitMarker(context, { @@ -11535,6 +11655,7 @@ async function persistExtractionBatchResult({ reason = "extraction-batch-complete", lastProcessedAssistantFloor = null, graphSnapshot = null, + persistSnapshot = null, persistDelta = null, } = {}) { ensureCurrentGraphRuntimeState(); @@ -11584,6 +11705,8 @@ async function persistExtractionBatchResult({ reason, lastProcessedAssistantFloor, persistDelta, + graphSnapshot, + persistSnapshot, graphDetached: persistGraphDetached, }, ); @@ -13317,6 +13440,8 @@ async function saveGraphToIndexedDb( persistRole = "primary", scheduleCloudUpload: scheduleCloudUploadOption = undefined, persistDelta = null, + graphSnapshot = null, + persistSnapshot = null, } = {}, ) { const normalizedChatId = normalizeChatIdCandidate(chatId); @@ -13380,8 +13505,21 @@ async function saveGraphToIndexedDb( !Array.isArray(persistDelta) ? cloneRuntimeDebugValue(persistDelta, persistDelta) : null; + const detachedGraphSnapshot = + graphSnapshot && + typeof graphSnapshot === "object" && + !Array.isArray(graphSnapshot) + ? graphSnapshot + : null; + const prebuiltPersistSnapshot = + persistSnapshot && + typeof persistSnapshot === "object" && + !Array.isArray(persistSnapshot) + ? persistSnapshot + : null; + const persistGraphInput = detachedGraphSnapshot || graph; let baseSnapshot = null; - let snapshot = null; + let snapshot = prebuiltPersistSnapshot; let delta = directPersistDelta; let persistDeltaBuildDiagnostics = null; let nativePersistModuleStatus = null; @@ -13390,6 +13528,7 @@ async function saveGraphToIndexedDb( let nativePersistPreloadMs = 0; let baseSnapshotReadMs = 0; let graphSnapshotBuildMs = 0; + let snapshotBuildDiagnostics = null; const persistDeltaStartedAt = readPersistDeltaDiagnosticsNow(); if (!delta) { @@ -13400,23 +13539,33 @@ async function saveGraphToIndexedDb( } baseSnapshotReadMs = readPersistDeltaDiagnosticsNow() - baseSnapshotReadStartedAt; - const graphSnapshotBuildStartedAt = readPersistDeltaDiagnosticsNow(); - snapshot = buildSnapshotFromGraph(graph, { - chatId: normalizedChatId, - revision: requestedRevision, - baseSnapshot, - lastModified: Date.now(), - meta: { - storagePrimary: localStore.storagePrimary, - storageMode: localStore.storageMode, - lastMutationReason: String(reason || "graph-save"), - integrity: - currentIdentity.integrity || graphPersistenceState.metadataIntegrity, - hostChatId: currentIdentity.hostChatId || "", - }, - }); - graphSnapshotBuildMs = - readPersistDeltaDiagnosticsNow() - graphSnapshotBuildStartedAt; + if (!snapshot) { + const graphSnapshotBuildStartedAt = readPersistDeltaDiagnosticsNow(); + snapshot = buildSnapshotFromGraph(persistGraphInput, { + chatId: normalizedChatId, + revision: requestedRevision, + baseSnapshot, + lastModified: Date.now(), + meta: { + storagePrimary: localStore.storagePrimary, + storageMode: localStore.storageMode, + lastMutationReason: String(reason || "graph-save"), + integrity: + currentIdentity.integrity || graphPersistenceState.metadataIntegrity, + hostChatId: currentIdentity.hostChatId || "", + }, + onDiagnostics(snapshotValue) { + snapshotBuildDiagnostics = + snapshotValue && + typeof snapshotValue === "object" && + !Array.isArray(snapshotValue) + ? snapshotValue + : null; + }, + }); + graphSnapshotBuildMs = + readPersistDeltaDiagnosticsNow() - graphSnapshotBuildStartedAt; + } } const nativePersistBridgeMode = String( currentSettings.persistNativeDeltaBridgeMode || "json", @@ -13588,6 +13737,7 @@ async function saveGraphToIndexedDb( reason, requestedRevision, markSyncDirty: true, + committedSnapshot: snapshot, }); const commitDiagnostics = commitResult?.diagnostics && @@ -13602,10 +13752,10 @@ async function saveGraphToIndexedDb( const committedLastModified = Number(commitResult?.lastModified || Date.now()); let scheduleUploadWarning = ""; - if (graph) { + if (persistGraphInput) { if (!snapshot) { const graphSnapshotBuildStartedAt = readPersistDeltaDiagnosticsNow(); - snapshot = buildSnapshotFromGraph(graph, { + snapshot = buildSnapshotFromGraph(persistGraphInput, { chatId: normalizedChatId, revision: committedRevision, baseSnapshot: baseSnapshot || undefined, @@ -13618,6 +13768,14 @@ async function saveGraphToIndexedDb( currentIdentity.integrity || graphPersistenceState.metadataIntegrity, hostChatId: currentIdentity.hostChatId || "", }, + onDiagnostics(snapshotValue) { + snapshotBuildDiagnostics = + snapshotValue && + typeof snapshotValue === "object" && + !Array.isArray(snapshotValue) + ? snapshotValue + : null; + }, }); graphSnapshotBuildMs += readPersistDeltaDiagnosticsNow() - graphSnapshotBuildStartedAt; @@ -13722,6 +13880,33 @@ async function saveGraphToIndexedDb( ), baseSnapshotReadMs: normalizePersistDeltaDiagnosticsMs(baseSnapshotReadMs), snapshotBuildMs: normalizePersistDeltaDiagnosticsMs(graphSnapshotBuildMs), + snapshotNodesMs: normalizePersistDeltaDiagnosticsMs( + snapshotBuildDiagnostics?.nodesMs, + ), + snapshotEdgesMs: normalizePersistDeltaDiagnosticsMs( + snapshotBuildDiagnostics?.edgesMs, + ), + snapshotTombstonesMs: normalizePersistDeltaDiagnosticsMs( + snapshotBuildDiagnostics?.tombstonesMs, + ), + snapshotStateMs: normalizePersistDeltaDiagnosticsMs( + snapshotBuildDiagnostics?.stateMs, + ), + snapshotMetaMs: normalizePersistDeltaDiagnosticsMs( + snapshotBuildDiagnostics?.metaMs, + ), + snapshotNodeCount: Math.max( + 0, + Math.floor(Number(snapshotBuildDiagnostics?.nodeCount || 0)), + ), + snapshotEdgeCount: Math.max( + 0, + Math.floor(Number(snapshotBuildDiagnostics?.edgeCount || 0)), + ), + snapshotTombstoneCount: Math.max( + 0, + Math.floor(Number(snapshotBuildDiagnostics?.tombstoneCount || 0)), + ), commitStorageKind: String( commitDiagnostics?.storageKind || localStore.storagePrimary || "", ), @@ -13742,9 +13927,21 @@ async function saveGraphToIndexedDb( commitManifestReadMs: normalizePersistDeltaDiagnosticsMs( commitDiagnostics?.manifestReadMs, ), + commitWalSerializeMs: normalizePersistDeltaDiagnosticsMs( + commitDiagnostics?.walSerializeMs, + ), + commitWalFileWriteMs: normalizePersistDeltaDiagnosticsMs( + commitDiagnostics?.walFileWriteMs, + ), commitWalWriteMs: normalizePersistDeltaDiagnosticsMs( commitDiagnostics?.walWriteMs, ), + commitManifestSerializeMs: normalizePersistDeltaDiagnosticsMs( + commitDiagnostics?.manifestSerializeMs, + ), + commitManifestFileWriteMs: normalizePersistDeltaDiagnosticsMs( + commitDiagnostics?.manifestFileWriteMs, + ), commitManifestWriteMs: normalizePersistDeltaDiagnosticsMs( commitDiagnostics?.manifestWriteMs, ), @@ -13784,6 +13981,34 @@ async function saveGraphToIndexedDb( "js", ) : ""; + const persistObservability = buildPersistObservabilitySummary( + persistDeltaDiagnostics, + ); + persistDeltaDiagnostics.pathKey = String( + persistObservability?.lastPathKey || "unknown", + ); + persistDeltaDiagnostics.reasonKey = String( + persistObservability?.lastReasonKey || "graph-save", + ); + persistDeltaDiagnostics.pathReasonKey = String( + persistObservability?.lastPathReasonKey || "unknown::graph-save", + ); + persistDeltaDiagnostics.pathSampleCount = Math.max( + 0, + Math.floor( + Number( + persistObservability?.byPath?.[persistDeltaDiagnostics.pathKey]?.count || 0, + ), + ), + ); + persistDeltaDiagnostics.reasonSampleCount = Math.max( + 0, + Math.floor( + Number( + persistObservability?.byReason?.[persistDeltaDiagnostics.reasonKey]?.count || 0, + ), + ), + ); const opfsWriteLockState = typeof db?.getWriteLockSnapshot === "function" @@ -13828,6 +14053,7 @@ async function saveGraphToIndexedDb( opfsWalDepth: localStoreDiagnostics.opfsWalDepth, opfsPendingBytes: localStoreDiagnostics.opfsPendingBytes, opfsCompactionState: localStoreDiagnostics.opfsCompactionState, + persistObservability, dualWriteLastResult: { action: "cache-mirror", target: localStore.storagePrimary, @@ -13924,6 +14150,7 @@ async function saveGraphToIndexedDb( opfsWalDepth: localStoreDiagnostics.opfsWalDepth, opfsPendingBytes: localStoreDiagnostics.opfsPendingBytes, opfsCompactionState: localStoreDiagnostics.opfsCompactionState, + persistObservability, dualWriteLastResult: { action: "save", target: localStore.storagePrimary, @@ -14077,6 +14304,104 @@ async function saveGraphToIndexedDb( } } +function normalizePersistObservabilityKey(value = "", fallback = "unknown") { + const normalized = String(value || "") + .trim() + .toLowerCase() + .replace(/\s+/g, "-") + .replace(/[^a-z0-9:_-]+/g, "-") + .replace(/-+/g, "-") + .replace(/^-+|-+$/g, ""); + return normalized || String(fallback || "unknown"); +} + +function trimPersistObservabilityBuckets(buckets = {}, maxEntries = 16) { + const entries = Object.values(buckets || {}).filter( + (entry) => entry && typeof entry === "object" && !Array.isArray(entry), + ); + entries.sort((left, right) => { + const countDelta = Number(right?.count || 0) - Number(left?.count || 0); + if (countDelta !== 0) return countDelta; + return String(right?.lastAt || "").localeCompare(String(left?.lastAt || "")); + }); + return Object.fromEntries( + entries.slice(0, Math.max(1, Math.floor(Number(maxEntries) || 16))).map((entry) => [ + String(entry.key || "unknown"), + entry, + ]), + ); +} + +function buildPersistObservabilitySummary(diagnostics = null) { + const source = + diagnostics && typeof diagnostics === "object" && !Array.isArray(diagnostics) + ? diagnostics + : {}; + const previous = + graphPersistenceState.persistObservability && + typeof graphPersistenceState.persistObservability === "object" && + !Array.isArray(graphPersistenceState.persistObservability) + ? cloneRuntimeDebugValue(graphPersistenceState.persistObservability, {}) + : {}; + const totalMs = normalizePersistDeltaDiagnosticsMs( + source.totalMs || source.buildMs || 0, + ); + const pathKey = normalizePersistObservabilityKey( + source.path || source.requestedBridgeMode || "unknown", + "unknown", + ); + const reasonKey = normalizePersistObservabilityKey( + source.saveReason || "graph-save", + "graph-save", + ); + const pathReasonKey = `${pathKey}::${reasonKey}`; + const recordedAt = new Date().toISOString(); + const recordBucket = (buckets = {}, key = "unknown") => { + const current = + buckets[key] && typeof buckets[key] === "object" && !Array.isArray(buckets[key]) + ? buckets[key] + : null; + const count = Math.max(0, Math.floor(Number(current?.count || 0))) + 1; + const totalBucketMs = normalizePersistDeltaDiagnosticsMs( + Number(current?.totalMs || 0) + totalMs, + ); + buckets[key] = { + key, + count, + totalMs: totalBucketMs, + avgMs: normalizePersistDeltaDiagnosticsMs(totalBucketMs / count), + maxMs: normalizePersistDeltaDiagnosticsMs( + Math.max(Number(current?.maxMs || 0), totalMs), + ), + lastMs: totalMs, + lastAt: recordedAt, + }; + return buckets; + }; + const nextByPath = recordBucket( + cloneRuntimeDebugValue(previous.byPath || {}, {}), + pathKey, + ); + const nextByReason = recordBucket( + cloneRuntimeDebugValue(previous.byReason || {}, {}), + reasonKey, + ); + const nextByPathReason = recordBucket( + cloneRuntimeDebugValue(previous.byPathReason || {}, {}), + pathReasonKey, + ); + return { + totalSamples: Math.max(0, Math.floor(Number(previous.totalSamples || 0))) + 1, + byPath: trimPersistObservabilityBuckets(nextByPath, 12), + byReason: trimPersistObservabilityBuckets(nextByReason, 16), + byPathReason: trimPersistObservabilityBuckets(nextByPathReason, 24), + lastPathKey: pathKey, + lastReasonKey: reasonKey, + lastPathReasonKey: pathReasonKey, + lastRecordedAt: recordedAt, + }; +} + function queueGraphPersistToIndexedDb( chatId, graph, @@ -14086,6 +14411,8 @@ function queueGraphPersistToIndexedDb( persistRole = "primary", scheduleCloudUpload = undefined, persistDelta = null, + graphSnapshot = null, + persistSnapshot = null, graphDetached = false, } = {}, ) { @@ -14134,17 +14461,21 @@ function queueGraphPersistToIndexedDb( revision: normalizedRevision, }; } - const graphSnapshot = graph - ? graphDetached === true - ? normalizeGraphRuntimeState(graph, normalizedChatId) - : cloneGraphForPersistence(graph, normalizedChatId) - : null; - return await saveGraphToIndexedDb(normalizedChatId, graphSnapshot, { + const persistGraphSnapshot = graphSnapshot + ? graphSnapshot + : graph + ? graphDetached === true + ? normalizeGraphRuntimeState(graph, normalizedChatId) + : cloneGraphForPersistence(graph, normalizedChatId) + : null; + return await saveGraphToIndexedDb(normalizedChatId, persistGraphSnapshot, { revision: normalizedRevision, reason, persistRole, scheduleCloudUpload, persistDelta, + graphSnapshot: persistGraphSnapshot, + persistSnapshot, }); }) .finally(() => { diff --git a/maintenance/extraction-controller.js b/maintenance/extraction-controller.js index 0f1d78f..f9c6cdc 100644 --- a/maintenance/extraction-controller.js +++ b/maintenance/extraction-controller.js @@ -380,10 +380,22 @@ async function buildCommittedBatchPersistSnapshot( } let persistDelta = null; + let persistSnapshot = null; const shouldUseNativePersistDelta = runtimeSettings?.persistUseNativeDelta === true && runtimeSettings?.graphNativeForceDisable !== true; const nativeFailOpen = runtimeSettings?.nativeEngineFailOpen !== false; + if (typeof runtime.buildSnapshotFromGraph === "function") { + persistSnapshot = runtime.buildSnapshotFromGraph(committedGraphSnapshot, { + chatId: + committedGraphSnapshot?.historyState?.chatId || + beforeSnapshot?.meta?.chatId || + "", + revision: Number(beforeSnapshot?.meta?.revision || 0) + 1, + baseSnapshot: beforeSnapshot || undefined, + lastModified: Date.now(), + }); + } if (typeof runtime.buildPersistDelta === "function") { if (shouldUseNativePersistDelta) { const preloadStartedAt = readNow(); @@ -403,7 +415,10 @@ async function buildCommittedBatchPersistSnapshot( } } - persistDelta = runtime.buildPersistDelta(beforeSnapshot, committedGraphSnapshot, { + persistDelta = runtime.buildPersistDelta( + beforeSnapshot, + persistSnapshot || committedGraphSnapshot, + { useNativeDelta: shouldUseNativePersistDelta, nativeFailOpen, persistNativeDeltaThresholdRecords: @@ -413,11 +428,13 @@ async function buildCommittedBatchPersistSnapshot( persistNativeDeltaThresholdSerializedChars: runtimeSettings?.persistNativeDeltaThresholdSerializedChars, persistNativeDeltaBridgeMode: runtimeSettings?.persistNativeDeltaBridgeMode, - }); + }, + ); } return { persistDelta, + persistSnapshot, persistGraphSnapshot: committedGraphSnapshot, committedBatchJournalEntry, afterSnapshot, @@ -717,6 +734,7 @@ export async function executeExtractionBatchController( reason: "extraction-batch-complete", lastProcessedAssistantFloor: endIdx, graphSnapshot: committedPersistState.persistGraphSnapshot, + persistSnapshot: committedPersistState.persistSnapshot, persistDelta: committedPersistState.persistDelta, }); const persistence = normalizePersistenceStateRecord(persistResult); diff --git a/sync/bme-db.js b/sync/bme-db.js index 8c75c83..1bf1dc8 100644 --- a/sync/bme-db.js +++ b/sync/bme-db.js @@ -646,6 +646,26 @@ export function buildSnapshotFromGraph(graph, options = {}) { !Array.isArray(options.baseSnapshot) ? options.baseSnapshot : {}; + const shouldCollectDiagnostics = typeof options?.onDiagnostics === "function"; + const snapshotStartedAt = shouldCollectDiagnostics ? readPersistDeltaNow() : 0; + const snapshotDiagnostics = shouldCollectDiagnostics + ? { + nodeCount: 0, + edgeCount: 0, + tombstoneCount: 0, + reusedNodeCount: 0, + reusedEdgeCount: 0, + reusedTombstoneCount: 0, + clonedNodeCount: 0, + clonedEdgeCount: 0, + clonedTombstoneCount: 0, + nodesMs: 0, + edgesMs: 0, + tombstonesMs: 0, + stateMs: 0, + metaMs: 0, + } + : null; const baseSnapshot = sanitizeSnapshot(baseSnapshotInput); const baseSnapshotView = normalizePersistSnapshotView(baseSnapshotInput); const nowMs = normalizeTimestamp(options.nowMs, Date.now()); @@ -674,6 +694,7 @@ export function buildSnapshotFromGraph(graph, options = {}) { baseSnapshotView.tombstones, ); + const nodesStartedAt = shouldCollectDiagnostics ? readPersistDeltaNow() : 0; const nodes = toArray(runtimeGraph?.nodes) .map((node) => { if (!node || typeof node !== "object" || Array.isArray(node)) { @@ -689,18 +710,29 @@ export function buildSnapshotFromGraph(graph, options = {}) { updatedAt: normalizedUpdatedAt, }) ) { + if (snapshotDiagnostics) { + snapshotDiagnostics.reusedNodeCount += 1; + } return baseNode; } const plainNode = clonePersistSnapshotRecord(node); if (!plainNode || typeof plainNode !== "object" || Array.isArray(plainNode)) { return null; } + if (snapshotDiagnostics) { + snapshotDiagnostics.clonedNodeCount += 1; + } plainNode.id = id; plainNode.updatedAt = normalizedUpdatedAt; return plainNode; }) .filter(Boolean); + if (snapshotDiagnostics) { + snapshotDiagnostics.nodeCount = nodes.length; + snapshotDiagnostics.nodesMs = readPersistDeltaNow() - nodesStartedAt; + } + const edgesStartedAt = shouldCollectDiagnostics ? readPersistDeltaNow() : 0; const edges = toArray(runtimeGraph?.edges) .map((edge) => { if (!edge || typeof edge !== "object" || Array.isArray(edge)) { @@ -719,12 +751,18 @@ export function buildSnapshotFromGraph(graph, options = {}) { updatedAt: normalizedUpdatedAt, }) ) { + if (snapshotDiagnostics) { + snapshotDiagnostics.reusedEdgeCount += 1; + } return baseEdge; } const plainEdge = clonePersistSnapshotRecord(edge); if (!plainEdge || typeof plainEdge !== "object" || Array.isArray(plainEdge)) { return null; } + if (snapshotDiagnostics) { + snapshotDiagnostics.clonedEdgeCount += 1; + } plainEdge.id = id; plainEdge.fromId = normalizedFromId; plainEdge.toId = normalizedToId; @@ -732,7 +770,12 @@ export function buildSnapshotFromGraph(graph, options = {}) { return plainEdge; }) .filter(Boolean); + if (snapshotDiagnostics) { + snapshotDiagnostics.edgeCount = edges.length; + snapshotDiagnostics.edgesMs = readPersistDeltaNow() - edgesStartedAt; + } + const tombstonesStartedAt = shouldCollectDiagnostics ? readPersistDeltaNow() : 0; const tombstones = toArray(options.tombstones ?? baseSnapshotView.tombstones) .map((record) => { if (!record || typeof record !== "object" || Array.isArray(record)) @@ -752,12 +795,18 @@ export function buildSnapshotFromGraph(graph, options = {}) { deletedAt: normalizedDeletedAt, }) ) { + if (snapshotDiagnostics) { + snapshotDiagnostics.reusedTombstoneCount += 1; + } return baseTombstone; } const plainRecord = clonePersistSnapshotRecord(record); if (!plainRecord || typeof plainRecord !== "object" || Array.isArray(plainRecord)) { return null; } + if (snapshotDiagnostics) { + snapshotDiagnostics.clonedTombstoneCount += 1; + } plainRecord.id = id; plainRecord.kind = normalizedKind; plainRecord.targetId = normalizedTargetId; @@ -766,7 +815,13 @@ export function buildSnapshotFromGraph(graph, options = {}) { return plainRecord; }) .filter(Boolean); + if (snapshotDiagnostics) { + snapshotDiagnostics.tombstoneCount = tombstones.length; + snapshotDiagnostics.tombstonesMs = + readPersistDeltaNow() - tombstonesStartedAt; + } + const stateStartedAt = shouldCollectDiagnostics ? readPersistDeltaNow() : 0; const state = { ...normalizeStateSnapshot(baseSnapshot), ...(options.state || {}), @@ -783,7 +838,11 @@ export function buildSnapshotFromGraph(graph, options = {}) { ? Number(runtimeGraph.historyState.extractionCount) : META_DEFAULT_EXTRACTION_COUNT, }; + if (snapshotDiagnostics) { + snapshotDiagnostics.stateMs = readPersistDeltaNow() - stateStartedAt; + } + const metaStartedAt = shouldCollectDiagnostics ? readPersistDeltaNow() : 0; const mergedMeta = { ...baseSnapshot.meta, ...(options.meta || {}), @@ -869,14 +928,26 @@ export function buildSnapshotFromGraph(graph, options = {}) { ? Number(runtimeGraph.version) : Number(baseSnapshot.meta?.[BME_RUNTIME_GRAPH_VERSION_META_KEY] || 0), }; + if (snapshotDiagnostics) { + snapshotDiagnostics.metaMs = readPersistDeltaNow() - metaStartedAt; + } - return { + const snapshotResult = { meta: mergedMeta, nodes, edges, tombstones, state, }; + if (snapshotDiagnostics) { + emitOptionalDiagnostics(options, { + ...snapshotDiagnostics, + runtimeMetaKeyCount: Object.keys(mergedMeta).length, + totalMs: readPersistDeltaNow() - snapshotStartedAt, + }); + } + + return snapshotResult; } function normalizeSnapshotMetaState(snapshot = {}) { @@ -1630,7 +1701,7 @@ function readPersistDeltaNow() { return Date.now(); } -function emitPersistDeltaDiagnostics(options = {}, snapshot = null) { +function emitOptionalDiagnostics(options = {}, snapshot = null) { if (typeof options?.onDiagnostics !== "function") return; try { options.onDiagnostics(snapshot ? toPlainData(snapshot, snapshot) : null); @@ -1639,6 +1710,10 @@ function emitPersistDeltaDiagnostics(options = {}, snapshot = null) { } } +function emitPersistDeltaDiagnostics(options = {}, snapshot = null) { + emitOptionalDiagnostics(options, snapshot); +} + function tryBuildNativePersistDelta( beforeSnapshot, afterSnapshot, @@ -2016,6 +2091,23 @@ export function buildPersistDelta(beforeSnapshot, afterSnapshot, options = {}) { } export function buildGraphFromSnapshot(snapshot, options = {}) { + const shouldCollectDiagnostics = typeof options?.onDiagnostics === "function"; + const hydrateStartedAt = shouldCollectDiagnostics ? readPersistDeltaNow() : 0; + const hydrateDiagnostics = shouldCollectDiagnostics + ? { + success: false, + nodeCount: 0, + edgeCount: 0, + tombstoneCount: 0, + nodesMs: 0, + edgesMs: 0, + runtimeMetaMs: 0, + stateMs: 0, + normalizeMs: 0, + integrityMs: 0, + integrityReasonCount: 0, + } + : null; const snapshotView = normalizePersistSnapshotView(snapshot); const snapshotMeta = snapshotView.meta && @@ -2048,8 +2140,24 @@ export function buildGraphFromSnapshot(snapshot, options = {}) { ) ? Number(snapshotMeta[BME_RUNTIME_GRAPH_VERSION_META_KEY]) : runtimeGraph.version; + + const hydrateNodesStartedAt = shouldCollectDiagnostics ? readPersistDeltaNow() : 0; runtimeGraph.nodes = toArray(toPlainData(snapshotView.nodes, [])); + if (hydrateDiagnostics) { + hydrateDiagnostics.nodeCount = runtimeGraph.nodes.length; + hydrateDiagnostics.nodesMs = readPersistDeltaNow() - hydrateNodesStartedAt; + } + + const hydrateEdgesStartedAt = shouldCollectDiagnostics ? readPersistDeltaNow() : 0; runtimeGraph.edges = toArray(toPlainData(snapshotView.edges, [])); + if (hydrateDiagnostics) { + hydrateDiagnostics.edgeCount = runtimeGraph.edges.length; + hydrateDiagnostics.edgesMs = readPersistDeltaNow() - hydrateEdgesStartedAt; + } + + const hydrateRuntimeMetaStartedAt = shouldCollectDiagnostics + ? readPersistDeltaNow() + : 0; runtimeGraph.batchJournal = toArray( toPlainData(snapshotMeta?.[BME_RUNTIME_BATCH_JOURNAL_META_KEY], []), ); @@ -2076,6 +2184,10 @@ export function buildGraphFromSnapshot(snapshot, options = {}) { snapshotMeta?.[BME_RUNTIME_SUMMARY_STATE_META_KEY], runtimeGraph.summaryState || {}, ); + if (hydrateDiagnostics) { + hydrateDiagnostics.runtimeMetaMs = + readPersistDeltaNow() - hydrateRuntimeMetaStartedAt; + } const rawKnowledgeState = runtimeGraph.knowledgeState && typeof runtimeGraph.knowledgeState === "object" && @@ -2095,6 +2207,7 @@ export function buildGraphFromSnapshot(snapshot, options = {}) { ? runtimeGraph.timelineState : {}; + const hydrateStateStartedAt = shouldCollectDiagnostics ? readPersistDeltaNow() : 0; runtimeGraph.historyState = { ...(runtimeGraph.historyState || {}), ...snapshotHistoryState, @@ -2183,8 +2296,16 @@ export function buildGraphFromSnapshot(snapshot, options = {}) { ) ? Number(snapshotMeta[BME_RUNTIME_LAST_PROCESSED_SEQ_META_KEY]) : Number(runtimeGraph.historyState.lastProcessedAssistantFloor); + if (hydrateDiagnostics) { + hydrateDiagnostics.tombstoneCount = toArray(snapshotView.tombstones).length; + hydrateDiagnostics.stateMs = readPersistDeltaNow() - hydrateStateStartedAt; + } + const normalizeStartedAt = shouldCollectDiagnostics ? readPersistDeltaNow() : 0; const normalizedGraph = normalizeGraphRuntimeState(runtimeGraph, chatId); + if (hydrateDiagnostics) { + hydrateDiagnostics.normalizeMs = readPersistDeltaNow() - normalizeStartedAt; + } if ( normalizedGraph.knowledgeState && typeof normalizedGraph.knowledgeState === "object" && @@ -2238,6 +2359,7 @@ export function buildGraphFromSnapshot(snapshot, options = {}) { ); const inconsistentReasons = []; + const integrityStartedAt = shouldCollectDiagnostics ? readPersistDeltaNow() : 0; if ( Number.isFinite(resolvedLastProcessedFloor) && Number.isFinite(resolvedLastProcessedSeq) && @@ -2255,8 +2377,20 @@ export function buildGraphFromSnapshot(snapshot, options = {}) { if (collectionId && collectionId !== expectedCollectionId) { inconsistentReasons.push("vector-collection-mismatch"); } + if (hydrateDiagnostics) { + hydrateDiagnostics.integrityMs = readPersistDeltaNow() - integrityStartedAt; + hydrateDiagnostics.integrityReasonCount = inconsistentReasons.length; + } if (inconsistentReasons.length > 0) { + if (hydrateDiagnostics) { + emitOptionalDiagnostics(options, { + ...hydrateDiagnostics, + success: false, + integrityReasons: [...inconsistentReasons], + totalMs: readPersistDeltaNow() - hydrateStartedAt, + }); + } const error = new Error( `图谱快照完整性校验失败: ${inconsistentReasons.join(", ")}`, ); @@ -2266,6 +2400,15 @@ export function buildGraphFromSnapshot(snapshot, options = {}) { throw error; } + if (hydrateDiagnostics) { + emitOptionalDiagnostics(options, { + ...hydrateDiagnostics, + success: true, + integrityReasons: [], + totalMs: readPersistDeltaNow() - hydrateStartedAt, + }); + } + return normalizedGraph; } @@ -3151,6 +3294,40 @@ export class BmeDatabase { return snapshot; } + async exportSnapshotProbe() { + const db = await this.open(); + const metaRows = await db.transaction("r", db.table("meta"), async () => + await db.table("meta").toArray(), + ); + const metaMap = toMetaMap(metaRows); + const meta = { + ...metaMap, + schemaVersion: BME_DB_SCHEMA_VERSION, + chatId: this.chatId, + revision: normalizeRevision(metaMap?.revision), + nodeCount: normalizeNonNegativeInteger(metaMap?.nodeCount, 0), + edgeCount: normalizeNonNegativeInteger(metaMap?.edgeCount, 0), + tombstoneCount: normalizeNonNegativeInteger(metaMap?.tombstoneCount, 0), + }; + const state = { + lastProcessedFloor: Number.isFinite(Number(meta.lastProcessedFloor)) + ? Number(meta.lastProcessedFloor) + : META_DEFAULT_LAST_PROCESSED_FLOOR, + extractionCount: Number.isFinite(Number(meta.extractionCount)) + ? Number(meta.extractionCount) + : META_DEFAULT_EXTRACTION_COUNT, + }; + return { + meta, + state, + nodes: [], + edges: [], + tombstones: [], + __stBmeProbeOnly: true, + __stBmeTombstonesOmitted: true, + }; + } + async importSnapshot(snapshot, options = {}) { const db = await this.open(); const normalizedSnapshot = sanitizeSnapshot(snapshot); diff --git a/sync/bme-opfs-store.js b/sync/bme-opfs-store.js index 9aad9d3..c1fb5ab 100644 --- a/sync/bme-opfs-store.js +++ b/sync/bme-opfs-store.js @@ -426,12 +426,16 @@ async function readJsonFile(parentHandle, name, fallbackValue = null) { return JSON.parse(text); } -async function writeJsonFile(parentHandle, name, value) { +async function writeJsonFile(parentHandle, name, value, options = {}) { + const serializedText = + typeof options?.serializedText === "string" + ? options.serializedText + : JSON.stringify(value); const fileHandle = await parentHandle.getFileHandle(String(name || ""), { create: true, }); const writable = await fileHandle.createWritable(); - await writable.write(JSON.stringify(value)); + await writable.write(serializedText); await writable.close(); return fileHandle; } @@ -2416,12 +2420,18 @@ export class OpfsGraphStore { runtimeMetaPatch: normalizedDelta.runtimeMetaPatch, countDelta: nextCountDelta, }; + const walSerializeStartedAt = readPersistCommitNow(); + const walSerializedText = JSON.stringify(walRecord); + const walSerializeMs = readPersistCommitNow() - walSerializeStartedAt; const walWriteStartedAt = readPersistCommitNow(); const walDirectory = await this._getWalDirectory(); const walFilename = buildOpfsV2WalFilename(nextRevision); - await writeJsonFile(walDirectory, walFilename, walRecord); - const walByteLength = JSON.stringify(walRecord).length; - const walWriteMs = readPersistCommitNow() - walWriteStartedAt; + await writeJsonFile(walDirectory, walFilename, walRecord, { + serializedText: walSerializedText, + }); + const walByteLength = walSerializedText.length; + const walFileWriteMs = readPersistCommitNow() - walWriteStartedAt; + const walWriteMs = walSerializeMs + walFileWriteMs; const hadPendingWal = normalizeRevision(manifest?.pendingLogFromRevision) <= currentHeadRevision; @@ -2448,12 +2458,40 @@ export class OpfsGraphStore { lastReason: reason, }, }; - const manifestWriteStartedAt = readPersistCommitNow(); - await this._writeManifest(nextManifest); - const manifestWriteMs = readPersistCommitNow() - manifestWriteStartedAt; + const manifestWriteDiagnostics = {}; + await this._writeManifest(nextManifest, { + diagnostics: manifestWriteDiagnostics, + }); + const manifestSerializeMs = Number( + manifestWriteDiagnostics.serializeMs || 0, + ); + const manifestFileWriteMs = Number( + manifestWriteDiagnostics.writeMs || 0, + ); + const manifestWriteMs = manifestSerializeMs + manifestFileWriteMs; + const committedSnapshot = + options?.committedSnapshot && + typeof options.committedSnapshot === "object" && + !Array.isArray(options.committedSnapshot) + ? sanitizeSnapshot(options.committedSnapshot) + : null; let cacheApplyMs = 0; - if (this._snapshotCache) { + if (committedSnapshot) { + const cacheApplyStartedAt = readPersistCommitNow(); + committedSnapshot.meta = { + ...committedSnapshot.meta, + ...nextMeta, + }; + committedSnapshot.state = normalizeSnapshotState(committedSnapshot); + committedSnapshot.meta.lastProcessedFloor = committedSnapshot.state.lastProcessedFloor; + committedSnapshot.meta.extractionCount = committedSnapshot.state.extractionCount; + committedSnapshot.meta.nodeCount = committedSnapshot.nodes.length; + committedSnapshot.meta.edgeCount = committedSnapshot.edges.length; + committedSnapshot.meta.tombstoneCount = committedSnapshot.tombstones.length; + this._snapshotCache = committedSnapshot; + cacheApplyMs = readPersistCommitNow() - cacheApplyStartedAt; + } else if (this._snapshotCache) { const cacheApplyStartedAt = readPersistCommitNow(); const nextSnapshot = applyOpfsV2DeltaToSnapshot( this._snapshotCache, @@ -2494,7 +2532,11 @@ export class OpfsGraphStore { readPersistCommitNow() - commitStartedAt, ), manifestReadMs: normalizePersistCommitMs(manifestReadMs), + walSerializeMs: normalizePersistCommitMs(walSerializeMs), + walFileWriteMs: normalizePersistCommitMs(walFileWriteMs), walWriteMs: normalizePersistCommitMs(walWriteMs), + manifestSerializeMs: normalizePersistCommitMs(manifestSerializeMs), + manifestFileWriteMs: normalizePersistCommitMs(manifestFileWriteMs), manifestWriteMs: normalizePersistCommitMs(manifestWriteMs), cacheApplyMs: normalizePersistCommitMs(cacheApplyMs), payloadBytes, @@ -2740,6 +2782,39 @@ export class OpfsGraphStore { return exported; } + async exportSnapshotProbe() { + const manifest = await this._ensureV2Ready(); + const meta = { + ...createDefaultMetaValues(this.chatId), + ...(manifest?.meta || {}), + chatId: this.chatId, + revision: normalizeRevision(manifest?.headRevision || manifest?.meta?.revision), + nodeCount: normalizeNonNegativeInteger(manifest?.meta?.nodeCount, 0), + edgeCount: normalizeNonNegativeInteger(manifest?.meta?.edgeCount, 0), + tombstoneCount: normalizeNonNegativeInteger(manifest?.meta?.tombstoneCount, 0), + storagePrimary: OPFS_STORE_KIND, + storageMode: this.storeMode, + schemaVersion: BME_DB_SCHEMA_VERSION, + }; + const state = { + lastProcessedFloor: Number.isFinite(Number(meta.lastProcessedFloor)) + ? Number(meta.lastProcessedFloor) + : META_DEFAULT_LAST_PROCESSED_FLOOR, + extractionCount: Number.isFinite(Number(meta.extractionCount)) + ? Number(meta.extractionCount) + : META_DEFAULT_EXTRACTION_COUNT, + }; + return { + meta, + state, + nodes: [], + edges: [], + tombstones: [], + __stBmeProbeOnly: true, + __stBmeTombstonesOmitted: true, + }; + } + async importSnapshot(snapshot, options = {}) { return await this._runSerializedWrite("importSnapshot", async () => { await this._ensureV2Ready({ awaitWrites: false }); @@ -2993,7 +3068,7 @@ export class OpfsGraphStore { return manifest; } - async _writeManifest(manifest = {}) { + async _writeManifest(manifest = {}, options = {}) { const chatDirectory = await this._getChatDirectory(); const nextManifest = { ...manifest, @@ -3017,7 +3092,24 @@ export class OpfsGraphStore { storageMode: this.storeMode, }, }; - await writeJsonFile(chatDirectory, OPFS_MANIFEST_FILENAME, nextManifest); + let serializedText = ""; + let serializeMs = 0; + if (options?.diagnostics && typeof options.diagnostics === "object") { + const serializeStartedAt = readPersistCommitNow(); + serializedText = JSON.stringify(nextManifest); + serializeMs = readPersistCommitNow() - serializeStartedAt; + } + const writeStartedAt = + options?.diagnostics && typeof options.diagnostics === "object" + ? readPersistCommitNow() + : 0; + await writeJsonFile(chatDirectory, OPFS_MANIFEST_FILENAME, nextManifest, { + serializedText, + }); + if (options?.diagnostics && typeof options.diagnostics === "object") { + options.diagnostics.serializeMs = serializeMs; + options.diagnostics.writeMs = readPersistCommitNow() - writeStartedAt; + } this._manifestCache = nextManifest; return nextManifest; } diff --git a/sync/bme-sync.js b/sync/bme-sync.js index a8078b9..80b66e0 100644 --- a/sync/bme-sync.js +++ b/sync/bme-sync.js @@ -47,6 +47,30 @@ export function buildRestoreSafetyChatId(chatId) { return `__restore_safety__${normalizeChatId(chatId)}`; } +function readSyncTimingNow() { + if (typeof performance === "object" && typeof performance.now === "function") { + return performance.now(); + } + return Date.now(); +} + +function normalizeSyncTimingMs(value = 0) { + return Math.round((Number(value) || 0) * 10) / 10; +} + +function finalizeSyncTimings(record = {}, startedAt = 0) { + const result = {}; + for (const [key, value] of Object.entries(record || {})) { + if (typeof value === "number" && Number.isFinite(value)) { + result[key] = normalizeSyncTimingMs(value); + } + } + if (startedAt > 0) { + result.totalMs = normalizeSyncTimingMs(readSyncTimingNow() - startedAt); + } + return result; +} + function resolveCloudStorageMode(options = {}) { const mode = typeof options.getCloudStorageMode === "function" @@ -494,14 +518,20 @@ async function resolveBackupLookupContext(chatId, options = {}) { } async function readBackupEnvelope(chatId, options = {}) { + const readStartedAt = readSyncTimingNow(); const normalizedChatId = normalizeChatId(chatId); + const lookupStartedAt = readSyncTimingNow(); const lookup = await resolveBackupLookupContext(normalizedChatId, options); + const lookupMs = readSyncTimingNow() - lookupStartedAt; const fetchImpl = getFetch(options); const fallbackFilename = buildBackupFilename(normalizedChatId); let lastMissingFilename = lookup.candidates[0]?.filename || fallbackFilename; + let networkMs = 0; + let parseMs = 0; for (const candidate of lookup.candidates) { try { + const networkStartedAt = readSyncTimingNow(); const response = await fetchImpl( `${candidate.serverPath || `/user/files/${encodeURIComponent(candidate.filename)}`}?t=${Date.now()}`, { @@ -509,6 +539,7 @@ async function readBackupEnvelope(chatId, options = {}) { cache: "no-store", }, ); + networkMs += readSyncTimingNow() - networkStartedAt; if (response.status === 404) { lastMissingFilename = candidate.filename; continue; @@ -521,10 +552,13 @@ async function readBackupEnvelope(chatId, options = {}) { envelope: null, reason: "backup-read-error", error: new Error(errorText || `HTTP ${response.status}`), + timings: finalizeSyncTimings({ lookupMs, networkMs, parseMs }, readStartedAt), }; } + const parseStartedAt = readSyncTimingNow(); const payload = await response.json(); + parseMs += readSyncTimingNow() - parseStartedAt; const envelope = normalizeBackupEnvelope(payload, normalizedChatId); if (!envelope) { return { @@ -532,6 +566,7 @@ async function readBackupEnvelope(chatId, options = {}) { filename: candidate.filename, envelope: null, reason: "invalid-backup", + timings: finalizeSyncTimings({ lookupMs, networkMs, parseMs }, readStartedAt), }; } return { @@ -539,6 +574,7 @@ async function readBackupEnvelope(chatId, options = {}) { filename: candidate.filename, envelope, reason: "ok", + timings: finalizeSyncTimings({ lookupMs, networkMs, parseMs }, readStartedAt), }; } catch (error) { return { @@ -547,6 +583,7 @@ async function readBackupEnvelope(chatId, options = {}) { envelope: null, reason: "backup-read-error", error, + timings: finalizeSyncTimings({ lookupMs, networkMs, parseMs }, readStartedAt), }; } } @@ -557,6 +594,7 @@ async function readBackupEnvelope(chatId, options = {}) { envelope: null, reason: "not-found", manifestError: lookup.manifestError, + timings: finalizeSyncTimings({ lookupMs, networkMs, parseMs }, readStartedAt), }; } @@ -581,10 +619,14 @@ async function syncDeletedBackupMeta(chatId, remainingEntry, options = {}) { } async function writeBackupEnvelope(envelope, chatId, options = {}) { + const writeStartedAt = readSyncTimingNow(); const normalizedChatId = normalizeChatId(chatId); const filename = buildBackupFilename(normalizedChatId); const fetchImpl = getFetch(options); + const serializeStartedAt = readSyncTimingNow(); const payload = JSON.stringify(envelope); + const serializeMs = readSyncTimingNow() - serializeStartedAt; + const uploadStartedAt = readSyncTimingNow(); const response = await fetchImpl("/api/files/upload", { method: "POST", headers: { @@ -596,16 +638,27 @@ async function writeBackupEnvelope(envelope, chatId, options = {}) { data: encodeBase64Utf8(payload), }), }); + const uploadMs = readSyncTimingNow() - uploadStartedAt; if (!response.ok) { const errorText = await response.text().catch(() => response.statusText); throw new Error(errorText || `HTTP ${response.status}`); } + const responseParseStartedAt = readSyncTimingNow(); const uploadResult = await response.json().catch(() => ({})); + const responseParseMs = readSyncTimingNow() - responseParseStartedAt; return { filename, path: String(uploadResult?.path || `/user/files/${filename}`), + timings: finalizeSyncTimings( + { + serializeMs, + uploadMs, + responseParseMs, + }, + writeStartedAt, + ), }; } @@ -1825,6 +1878,7 @@ async function resolveSyncFilenameCandidates(chatId, options = {}) { } async function readRemoteSnapshot(chatId, options = {}) { + const readStartedAt = readSyncTimingNow(); const normalizedChatId = normalizeChatId(chatId); if (!normalizedChatId) { return { @@ -1832,15 +1886,22 @@ async function readRemoteSnapshot(chatId, options = {}) { status: "missing-chat-id", filename: "", snapshot: null, + timings: finalizeSyncTimings({}, readStartedAt), }; } const fetchImpl = getFetch(options); + const resolveStartedAt = readSyncTimingNow(); const candidateFilenames = await resolveSyncFilenameCandidates( normalizedChatId, options, ); + const resolveCandidatesMs = readSyncTimingNow() - resolveStartedAt; let lastNotFoundFilename = candidateFilenames[0] || ""; + let networkMs = 0; + let parseMs = 0; + let chunkReadMs = 0; + let normalizeMs = 0; for (const filename of candidateFilenames) { const cacheBust = `t=${Date.now()}`; @@ -1848,10 +1909,12 @@ async function readRemoteSnapshot(chatId, options = {}) { let response; try { + const networkStartedAt = readSyncTimingNow(); response = await fetchImpl(url, { method: "GET", cache: "no-store", }); + networkMs += readSyncTimingNow() - networkStartedAt; } catch (error) { console.warn("[ST-BME] 读取远端同步文件失败:", error); return { @@ -1860,6 +1923,10 @@ async function readRemoteSnapshot(chatId, options = {}) { filename, snapshot: null, error, + timings: finalizeSyncTimings( + { resolveCandidatesMs, networkMs, parseMs, chunkReadMs, normalizeMs }, + readStartedAt, + ), }; } @@ -1879,14 +1946,20 @@ async function readRemoteSnapshot(chatId, options = {}) { snapshot: null, error, statusCode: response.status, + timings: finalizeSyncTimings( + { resolveCandidatesMs, networkMs, parseMs, chunkReadMs, normalizeMs }, + readStartedAt, + ), }; } try { + const parseStartedAt = readSyncTimingNow(); const remotePayload = await response.json(); + parseMs += readSyncTimingNow() - parseStartedAt; let snapshot = null; if (Number(remotePayload?.formatVersion || 0) === BME_REMOTE_SYNC_FORMAT_VERSION_V2) { - snapshot = await readRemoteSnapshotV2Manifest( + const manifestResult = await readRemoteSnapshotV2Manifest( remotePayload, normalizedChatId, { @@ -1894,8 +1967,13 @@ async function readRemoteSnapshot(chatId, options = {}) { filename, }, ); + snapshot = manifestResult.snapshot; + chunkReadMs += Number(manifestResult?.timings?.chunkReadMs || 0); + normalizeMs += Number(manifestResult?.timings?.normalizeMs || 0); } else { + const normalizeStartedAt = readSyncTimingNow(); snapshot = normalizeSyncSnapshot(remotePayload, normalizedChatId); + normalizeMs += readSyncTimingNow() - normalizeStartedAt; } rememberResolvedSyncFilename(normalizedChatId, filename); return { @@ -1903,6 +1981,10 @@ async function readRemoteSnapshot(chatId, options = {}) { status: "ok", filename, snapshot, + timings: finalizeSyncTimings( + { resolveCandidatesMs, networkMs, parseMs, chunkReadMs, normalizeMs }, + readStartedAt, + ), }; } catch (error) { console.warn("[ST-BME] 解析远端同步文件失败:", error); @@ -1912,6 +1994,10 @@ async function readRemoteSnapshot(chatId, options = {}) { filename, snapshot: null, error, + timings: finalizeSyncTimings( + { resolveCandidatesMs, networkMs, parseMs, chunkReadMs, normalizeMs }, + readStartedAt, + ), }; } } @@ -1921,6 +2007,10 @@ async function readRemoteSnapshot(chatId, options = {}) { status: "not-found", filename: lastNotFoundFilename, snapshot: null, + timings: finalizeSyncTimings( + { resolveCandidatesMs, networkMs, parseMs, chunkReadMs, normalizeMs }, + readStartedAt, + ), }; } @@ -1944,17 +2034,21 @@ async function readRemoteJsonFile(filename, options = {}) { } async function readRemoteSnapshotV2Manifest(manifest = {}, chatId = "", options = {}) { + const readStartedAt = readSyncTimingNow(); const normalizedChatId = normalizeChatId(chatId); const chunks = Array.isArray(manifest?.chunks) ? manifest.chunks : []; const nodes = []; const edges = []; const tombstones = []; let runtimeMeta = {}; + let chunkReadMs = 0; for (const chunk of chunks) { const filename = String(chunk?.filename || "").trim(); if (!filename) continue; + const chunkStartedAt = readSyncTimingNow(); const payload = await readRemoteJsonFile(filename, options); + chunkReadMs += readSyncTimingNow() - chunkStartedAt; const records = Array.isArray(payload?.records) ? payload.records : []; switch (String(chunk.kind || "").trim()) { case "nodes": @@ -1977,7 +2071,8 @@ async function readRemoteSnapshotV2Manifest(manifest = {}, chatId = "", options } } - return normalizeSyncSnapshot( + const normalizeStartedAt = readSyncTimingNow(); + const snapshot = normalizeSyncSnapshot( { meta: { ...runtimeMeta, @@ -1994,55 +2089,94 @@ async function readRemoteSnapshotV2Manifest(manifest = {}, chatId = "", options }, normalizedChatId, ); + const normalizeMs = readSyncTimingNow() - normalizeStartedAt; + return { + snapshot, + timings: finalizeSyncTimings( + { + chunkReadMs, + normalizeMs, + }, + readStartedAt, + ), + }; } async function writeSnapshotToRemote(snapshot, chatId, options = {}) { + const writeStartedAt = readSyncTimingNow(); const normalizedChatId = normalizeChatId(chatId); const normalizedSnapshot = normalizeSyncSnapshot(snapshot, normalizedChatId); const filename = await resolveSyncFilename(normalizedChatId, options); const fetchImpl = getFetch(options); + const envelopeBuildStartedAt = readSyncTimingNow(); const syncEnvelope = buildRemoteSyncEnvelopeV2( normalizedSnapshot, normalizedChatId, filename, ); + const envelopeBuildMs = readSyncTimingNow() - envelopeBuildStartedAt; const requestHeaders = { ...getRequestHeadersSafe(options), "Content-Type": "application/json", }; + let chunkSerializeMs = 0; + let chunkUploadMs = 0; for (const chunk of syncEnvelope.chunks) { + const serializeStartedAt = readSyncTimingNow(); + const chunkPayload = JSON.stringify(chunk.payload, null, 2); + chunkSerializeMs += readSyncTimingNow() - serializeStartedAt; + const uploadStartedAt = readSyncTimingNow(); const chunkResponse = await fetchImpl("/api/files/upload", { method: "POST", headers: requestHeaders, body: JSON.stringify({ name: chunk.filename, - data: encodeBase64Utf8(JSON.stringify(chunk.payload, null, 2)), + data: encodeBase64Utf8(chunkPayload), }), }); + chunkUploadMs += readSyncTimingNow() - uploadStartedAt; if (!chunkResponse.ok) { const errorText = await chunkResponse.text().catch(() => chunkResponse.statusText); throw new Error(errorText || `HTTP ${chunkResponse.status}`); } } + const manifestSerializeStartedAt = readSyncTimingNow(); + const manifestPayload = JSON.stringify(syncEnvelope.manifest, null, 2); + const manifestSerializeMs = readSyncTimingNow() - manifestSerializeStartedAt; + const manifestUploadStartedAt = readSyncTimingNow(); const response = await fetchImpl("/api/files/upload", { method: "POST", headers: requestHeaders, body: JSON.stringify({ name: filename, - data: encodeBase64Utf8(JSON.stringify(syncEnvelope.manifest, null, 2)), + data: encodeBase64Utf8(manifestPayload), }), }); + const manifestUploadMs = readSyncTimingNow() - manifestUploadStartedAt; if (!response.ok) { const errorText = await response.text().catch(() => response.statusText); throw new Error(errorText || `HTTP ${response.status}`); } + const responseParseStartedAt = readSyncTimingNow(); const uploadResult = await response.json().catch(() => ({})); + const responseParseMs = readSyncTimingNow() - responseParseStartedAt; return { filename, path: String(uploadResult?.path || ""), payload: syncEnvelope.manifest, + timings: finalizeSyncTimings( + { + envelopeBuildMs, + chunkSerializeMs, + chunkUploadMs, + manifestSerializeMs, + manifestUploadMs, + responseParseMs, + }, + writeStartedAt, + ), }; } @@ -2160,15 +2294,19 @@ export async function backupToServer(chatId, options = {}) { backedUp: false, chatId: "", reason: "missing-chat-id", + timings: finalizeSyncTimings({}, readSyncTimingNow()), }; } + const backupStartedAt = readSyncTimingNow(); try { const db = await getDb(normalizedChatId, options); + const exportStartedAt = readSyncTimingNow(); const snapshot = normalizeSyncSnapshot( await db.exportSnapshot(), normalizedChatId, ); + const exportMs = readSyncTimingNow() - exportStartedAt; const nowMs = Date.now(); const deviceId = getOrCreateDeviceId(); @@ -2179,6 +2317,7 @@ export async function backupToServer(chatId, options = {}) { nowMs, ); + const envelopeBuildStartedAt = readSyncTimingNow(); const backupSnapshot = buildManualBackupSnapshot(snapshot, normalizedChatId); const envelope = { kind: "st-bme-backup", @@ -2188,15 +2327,18 @@ export async function backupToServer(chatId, options = {}) { sourceDeviceId: deviceId, snapshot: backupSnapshot, }; + const envelopeBuildMs = readSyncTimingNow() - envelopeBuildStartedAt; const uploadResult = await writeBackupEnvelope( envelope, normalizedChatId, options, ); + const uploadTimings = uploadResult?.timings || {}; const serializedEnvelope = JSON.stringify(envelope); try { + const manifestWriteStartedAt = readSyncTimingNow(); await upsertBackupManifestEntry( { filename: uploadResult.filename, @@ -2210,6 +2352,37 @@ export async function backupToServer(chatId, options = {}) { }, options, ); + const manifestWriteMs = readSyncTimingNow() - manifestWriteStartedAt; + const metaPatchStartedAt = readSyncTimingNow(); + await patchDbMeta(db, { + deviceId, + syncDirty: false, + syncDirtyReason: "", + lastBackupUploadedAt: nowMs, + lastBackupFilename: uploadResult.filename, + }); + const metaPatchMs = readSyncTimingNow() - metaPatchStartedAt; + + return { + backedUp: true, + chatId: normalizedChatId, + filename: uploadResult.filename, + remotePath: uploadResult.path, + revision: normalizeRevision(snapshot.meta.revision), + backupTime: nowMs, + timings: finalizeSyncTimings( + { + exportMs, + envelopeBuildMs, + uploadMs: Number(uploadTimings.totalMs || 0), + envelopeSerializeMs: Number(uploadTimings.serializeMs || 0), + envelopeResponseParseMs: Number(uploadTimings.responseParseMs || 0), + manifestWriteMs, + metaPatchMs, + }, + backupStartedAt, + ), + }; } catch (manifestError) { return { backedUp: false, @@ -2219,25 +2392,18 @@ export async function backupToServer(chatId, options = {}) { reason: "backup-manifest-error", backupUploaded: true, error: manifestError, + timings: finalizeSyncTimings( + { + exportMs, + envelopeBuildMs, + uploadMs: Number(uploadTimings.totalMs || 0), + envelopeSerializeMs: Number(uploadTimings.serializeMs || 0), + envelopeResponseParseMs: Number(uploadTimings.responseParseMs || 0), + }, + backupStartedAt, + ), }; } - - await patchDbMeta(db, { - deviceId, - syncDirty: false, - syncDirtyReason: "", - lastBackupUploadedAt: nowMs, - lastBackupFilename: uploadResult.filename, - }); - - return { - backedUp: true, - chatId: normalizedChatId, - filename: uploadResult.filename, - remotePath: uploadResult.path, - revision: normalizeRevision(snapshot.meta.revision), - backupTime: nowMs, - }; } catch (error) { console.warn("[ST-BME] 手动备份到云端失败:", error); return { @@ -2245,6 +2411,7 @@ export async function backupToServer(chatId, options = {}) { chatId: normalizedChatId, reason: "backup-error", error, + timings: finalizeSyncTimings({}, backupStartedAt), }; } } @@ -2256,18 +2423,30 @@ export async function restoreFromServer(chatId, options = {}) { restored: false, chatId: "", reason: "missing-chat-id", + timings: finalizeSyncTimings({}, readSyncTimingNow()), }; } + const restoreStartedAt = readSyncTimingNow(); try { const db = await getDb(normalizedChatId, options); const remoteResult = await readBackupEnvelope(normalizedChatId, options); + const downloadTimings = remoteResult?.timings || {}; if (!remoteResult.exists || !remoteResult.envelope) { return { restored: false, chatId: normalizedChatId, filename: remoteResult.filename || "", reason: remoteResult.reason || "backup-missing", + timings: finalizeSyncTimings( + { + downloadMs: Number(downloadTimings.totalMs || 0), + lookupMs: Number(downloadTimings.lookupMs || 0), + networkMs: Number(downloadTimings.networkMs || 0), + envelopeParseMs: Number(downloadTimings.parseMs || 0), + }, + restoreStartedAt, + ), }; } @@ -2278,6 +2457,15 @@ export async function restoreFromServer(chatId, options = {}) { chatId: normalizedChatId, filename: remoteResult.filename, reason: "backup-version-mismatch", + timings: finalizeSyncTimings( + { + downloadMs: Number(downloadTimings.totalMs || 0), + lookupMs: Number(downloadTimings.lookupMs || 0), + networkMs: Number(downloadTimings.networkMs || 0), + envelopeParseMs: Number(downloadTimings.parseMs || 0), + }, + restoreStartedAt, + ), }; } @@ -2287,6 +2475,15 @@ export async function restoreFromServer(chatId, options = {}) { chatId: normalizedChatId, filename: remoteResult.filename, reason: "backup-chat-id-mismatch", + timings: finalizeSyncTimings( + { + downloadMs: Number(downloadTimings.totalMs || 0), + lookupMs: Number(downloadTimings.lookupMs || 0), + networkMs: Number(downloadTimings.networkMs || 0), + envelopeParseMs: Number(downloadTimings.parseMs || 0), + }, + restoreStartedAt, + ), }; } @@ -2304,26 +2501,42 @@ export async function restoreFromServer(chatId, options = {}) { chatId: normalizedChatId, filename: remoteResult.filename, reason: "snapshot-chat-id-mismatch", + timings: finalizeSyncTimings( + { + downloadMs: Number(downloadTimings.totalMs || 0), + lookupMs: Number(downloadTimings.lookupMs || 0), + networkMs: Number(downloadTimings.networkMs || 0), + envelopeParseMs: Number(downloadTimings.parseMs || 0), + }, + restoreStartedAt, + ), }; } + const localExportStartedAt = readSyncTimingNow(); const localSnapshot = normalizeSyncSnapshot( await db.exportSnapshot(), normalizedChatId, ); + const localExportMs = readSyncTimingNow() - localExportStartedAt; + const safetySnapshotStartedAt = readSyncTimingNow(); await createRestoreSafetySnapshot( normalizedChatId, localSnapshot, options, ); + const safetySnapshotMs = readSyncTimingNow() - safetySnapshotStartedAt; + const importStartedAt = readSyncTimingNow(); await db.importSnapshot(snapshot, { mode: "replace", preserveRevision: true, revision: normalizeRevision(snapshot.meta.revision), markSyncDirty: false, }); + const importMs = readSyncTimingNow() - importStartedAt; + const metaPatchStartedAt = readSyncTimingNow(); await patchDbMeta(db, { deviceId: getOrCreateDeviceId(), syncDirty: false, @@ -2332,12 +2545,15 @@ export async function restoreFromServer(chatId, options = {}) { lastBackupFilename: remoteResult.filename || buildBackupFilename(normalizedChatId), }); + const metaPatchMs = readSyncTimingNow() - metaPatchStartedAt; + const hookStartedAt = readSyncTimingNow(); await invokeSyncAppliedHook(options, { chatId: normalizedChatId, action: "restore-backup", revision: normalizeRevision(snapshot.meta.revision), }); + const hookMs = readSyncTimingNow() - hookStartedAt; return { restored: true, @@ -2345,6 +2561,20 @@ export async function restoreFromServer(chatId, options = {}) { filename: remoteResult.filename, revision: normalizeRevision(snapshot.meta.revision), backupTime: normalizeTimestamp(envelope.createdAt, 0), + timings: finalizeSyncTimings( + { + downloadMs: Number(downloadTimings.totalMs || 0), + lookupMs: Number(downloadTimings.lookupMs || 0), + networkMs: Number(downloadTimings.networkMs || 0), + envelopeParseMs: Number(downloadTimings.parseMs || 0), + localExportMs, + safetySnapshotMs, + importMs, + metaPatchMs, + hookMs, + }, + restoreStartedAt, + ), }; } catch (error) { console.warn("[ST-BME] 从云端恢复备份失败:", error); @@ -2353,6 +2583,7 @@ export async function restoreFromServer(chatId, options = {}) { chatId: normalizedChatId, reason: "restore-error", error, + timings: finalizeSyncTimings({}, restoreStartedAt), }; } } @@ -2455,12 +2686,16 @@ export async function upload(chatId, options = {}) { uploaded: false, chatId: "", reason: "missing-chat-id", + timings: finalizeSyncTimings({}, readSyncTimingNow()), }; } + const uploadStartedAt = readSyncTimingNow(); try { const db = await getDb(normalizedChatId, options); + const exportStartedAt = readSyncTimingNow(); const localSnapshot = normalizeSyncSnapshot(await db.exportSnapshot(), normalizedChatId); + const exportMs = readSyncTimingNow() - exportStartedAt; const nowMs = Date.now(); const deviceId = getOrCreateDeviceId(); @@ -2469,7 +2704,9 @@ export async function upload(chatId, options = {}) { localSnapshot.meta.lastModified = normalizeTimestamp(localSnapshot.meta.lastModified, nowMs); const uploadResult = await writeSnapshotToRemote(localSnapshot, normalizedChatId, options); + const uploadTimings = uploadResult?.timings || {}; + const metaPatchStartedAt = readSyncTimingNow(); await patchDbMeta(db, { deviceId, lastSyncUploadedAt: nowMs, @@ -2479,6 +2716,7 @@ export async function upload(chatId, options = {}) { lastModified: localSnapshot.meta.lastModified, remoteSyncFormatVersion: BME_REMOTE_SYNC_FORMAT_VERSION_V2, }); + const metaPatchMs = readSyncTimingNow() - metaPatchStartedAt; return { uploaded: true, @@ -2486,6 +2724,19 @@ export async function upload(chatId, options = {}) { filename: uploadResult.filename, remotePath: uploadResult.path, revision: normalizeRevision(localSnapshot.meta.revision), + timings: finalizeSyncTimings( + { + exportMs, + envelopeBuildMs: Number(uploadTimings.envelopeBuildMs || 0), + chunkSerializeMs: Number(uploadTimings.chunkSerializeMs || 0), + chunkUploadMs: Number(uploadTimings.chunkUploadMs || 0), + manifestSerializeMs: Number(uploadTimings.manifestSerializeMs || 0), + manifestUploadMs: Number(uploadTimings.manifestUploadMs || 0), + responseParseMs: Number(uploadTimings.responseParseMs || 0), + metaPatchMs, + }, + uploadStartedAt, + ), }; } catch (error) { console.warn("[ST-BME] 上传同步文件失败:", error); @@ -2494,6 +2745,7 @@ export async function upload(chatId, options = {}) { chatId: normalizedChatId, reason: "upload-error", error, + timings: finalizeSyncTimings({}, uploadStartedAt), }; } } @@ -2506,12 +2758,15 @@ export async function download(chatId, options = {}) { exists: false, chatId: "", reason: "missing-chat-id", + timings: finalizeSyncTimings({}, readSyncTimingNow()), }; } + const downloadStartedAt = readSyncTimingNow(); try { const db = await getDb(normalizedChatId, options); const remoteResult = await readRemoteSnapshot(normalizedChatId, options); + const remoteTimings = remoteResult?.timings || {}; if (!remoteResult.exists || !remoteResult.snapshot) { return { @@ -2520,6 +2775,16 @@ export async function download(chatId, options = {}) { chatId: normalizedChatId, filename: remoteResult.filename || "", reason: remoteResult.status || "remote-missing", + timings: finalizeSyncTimings( + { + resolveCandidatesMs: Number(remoteTimings.resolveCandidatesMs || 0), + networkMs: Number(remoteTimings.networkMs || 0), + parseMs: Number(remoteTimings.parseMs || 0), + chunkReadMs: Number(remoteTimings.chunkReadMs || 0), + normalizeMs: Number(remoteTimings.normalizeMs || 0), + }, + downloadStartedAt, + ), }; } @@ -2530,13 +2795,16 @@ export async function download(chatId, options = {}) { ); const remoteRevision = normalizeRevision(remoteSnapshot.meta.revision); + const importStartedAt = readSyncTimingNow(); await db.importSnapshot(remoteSnapshot, { mode: "replace", preserveRevision: true, revision: remoteRevision, markSyncDirty: false, }); + const importMs = readSyncTimingNow() - importStartedAt; + const metaPatchStartedAt = readSyncTimingNow(); await patchDbMeta(db, { deviceId: getOrCreateDeviceId(), lastSyncDownloadedAt: Date.now(), @@ -2545,12 +2813,15 @@ export async function download(chatId, options = {}) { syncDirtyReason: "", remoteSyncFormatVersion: BME_REMOTE_SYNC_FORMAT_VERSION_V2, }); + const metaPatchMs = readSyncTimingNow() - metaPatchStartedAt; + const hookStartedAt = readSyncTimingNow(); await invokeSyncAppliedHook(options, { chatId: normalizedChatId, action: "download", revision: remoteRevision, }); + const hookMs = readSyncTimingNow() - hookStartedAt; return { downloaded: true, @@ -2558,6 +2829,19 @@ export async function download(chatId, options = {}) { chatId: normalizedChatId, filename: remoteResult.filename, revision: remoteRevision, + timings: finalizeSyncTimings( + { + resolveCandidatesMs: Number(remoteTimings.resolveCandidatesMs || 0), + networkMs: Number(remoteTimings.networkMs || 0), + parseMs: Number(remoteTimings.parseMs || 0), + chunkReadMs: Number(remoteTimings.chunkReadMs || 0), + normalizeMs: Number(remoteTimings.normalizeMs || 0), + importMs, + metaPatchMs, + hookMs, + }, + downloadStartedAt, + ), }; } catch (error) { console.warn("[ST-BME] 下载同步文件失败:", error); @@ -2567,6 +2851,7 @@ export async function download(chatId, options = {}) { chatId: normalizedChatId, reason: "download-error", error, + timings: finalizeSyncTimings({}, downloadStartedAt), }; } } diff --git a/tests/graph-persistence.mjs b/tests/graph-persistence.mjs index 62d8f13..438dd36 100644 --- a/tests/graph-persistence.mjs +++ b/tests/graph-persistence.mjs @@ -3239,6 +3239,166 @@ result = { ); } +{ + const chatId = "chat-idb-direct-delta-prebuilt-persist-snapshot"; + const baseGraph = createMeaningfulGraph(chatId, "direct-delta-base"); + const runtimeGraph = createMeaningfulGraph(chatId, "direct-delta-after"); + const baseSnapshot = buildSnapshotFromGraph(baseGraph, { + chatId, + revision: 7, + }); + const persistSnapshot = buildSnapshotFromGraph(runtimeGraph, { + chatId, + revision: 8, + baseSnapshot, + }); + const directDelta = buildPersistDelta(baseSnapshot, persistSnapshot, { + useNativeDelta: false, + }); + const harness = await createGraphPersistenceHarness({ + chatId, + globalChatId: chatId, + chatMetadata: { + integrity: "meta-idb-direct-delta-prebuilt-persist-snapshot", + }, + indexedDbSnapshot: baseSnapshot, + }); + harness.api.setCurrentGraph(runtimeGraph); + harness.api.setGraphPersistenceState({ + loadState: "loaded", + chatId, + revision: 8, + lastPersistedRevision: 0, + writesBlocked: false, + }); + + const originalBuildSnapshotFromGraph = harness.runtimeContext.buildSnapshotFromGraph; + let buildSnapshotCallCount = 0; + harness.runtimeContext.buildSnapshotFromGraph = (...args) => { + buildSnapshotCallCount += 1; + return originalBuildSnapshotFromGraph(...args); + }; + + const result = await harness.api.saveGraphToIndexedDb(chatId, runtimeGraph, { + revision: 8, + reason: "direct-delta-prebuilt-persist-snapshot-save", + scheduleCloudUpload: false, + persistDelta: directDelta, + persistSnapshot, + }); + + assert.equal(result.saved, true); + assert.equal( + buildSnapshotCallCount, + 0, + "direct-delta 且已提供 persistSnapshot 时不应再次构建 snapshot", + ); + assert.equal(result.snapshot?.meta?.revision, 8); + assert.equal(harness.api.getIndexedDbSnapshot()?.meta?.revision, 8); +} + +{ + const chatId = "chat-indexeddb-probe-empty-early-return"; + const persistedSnapshot = { + meta: { revision: 0, chatId }, + nodes: [], + edges: [], + tombstones: [], + state: { + lastProcessedFloor: -1, + extractionCount: 0, + }, + }; + const harness = await createGraphPersistenceHarness({ + chatId, + globalChatId: chatId, + chatMetadata: { + integrity: "meta-indexeddb-probe-empty-early-return", + }, + indexedDbSnapshot: persistedSnapshot, + }); + harness.runtimeContext.__globalChatId = chatId; + harness.runtimeContext.__chatContext.chatId = chatId; + harness.api.setChatContext({ + ...harness.api.getChatContext(), + chatId, + chatMetadata: { + integrity: "meta-indexeddb-probe-empty-early-return", + }, + }); + harness.api.setCurrentGraph( + createMeaningfulGraph(chatId, "probe-empty-runtime-current"), + ); + harness.api.setGraphPersistenceState({ + loadState: "loaded", + chatId, + revision: 1, + lastPersistedRevision: 1, + storagePrimary: "indexeddb", + storageMode: "indexeddb", + writesBlocked: false, + }); + + const originalCreateDb = harness.runtimeContext.BmeChatManager.prototype._createDb; + let exportSnapshotCalls = 0; + let exportProbeCalls = 0; + harness.runtimeContext.BmeChatManager.prototype._createDb = function(dbChatId = "") { + const baseDb = originalCreateDb.call(this, dbChatId); + return { + ...baseDb, + async exportSnapshot() { + exportSnapshotCalls += 1; + return await baseDb.exportSnapshot(); + }, + async exportSnapshotProbe() { + exportProbeCalls += 1; + const snapshot = harness.api.getIndexedDbSnapshotForChat(dbChatId) || { + meta: { revision: 0, chatId: String(dbChatId || "") }, + state: { lastProcessedFloor: -1, extractionCount: 0 }, + nodes: [], + edges: [], + tombstones: [], + }; + return { + meta: { + ...(snapshot.meta || {}), + chatId: String(dbChatId || ""), + revision: Number(snapshot?.meta?.revision || 0), + nodeCount: Array.isArray(snapshot?.nodes) ? snapshot.nodes.length : 0, + edgeCount: Array.isArray(snapshot?.edges) ? snapshot.edges.length : 0, + tombstoneCount: Array.isArray(snapshot?.tombstones) + ? snapshot.tombstones.length + : 0, + }, + state: { + lastProcessedFloor: Number(snapshot?.state?.lastProcessedFloor ?? -1), + extractionCount: Number(snapshot?.state?.extractionCount ?? 0), + }, + nodes: [], + edges: [], + tombstones: [], + __stBmeProbeOnly: true, + __stBmeTombstonesOmitted: true, + }; + }, + }; + }; + + const result = await harness.api.loadGraphFromIndexedDb(chatId, { + source: "probe-empty-early-return", + attemptIndex: 0, + }); + + assert.equal(result.loaded, false); + assert.equal(exportProbeCalls, 1); + assert.equal( + exportSnapshotCalls, + 0, + "empty/probe 早退应在 probe 阶段终止，而不是继续全量导出 snapshot", + ); + harness.runtimeContext.BmeChatManager.prototype._createDb = originalCreateDb; +} + { const harness = await createGraphPersistenceHarness({ chatId: "chat-pending-persist-retry", diff --git a/tests/indexeddb-persistence.mjs b/tests/indexeddb-persistence.mjs index 5d31269..f9f0855 100644 --- a/tests/indexeddb-persistence.mjs +++ b/tests/indexeddb-persistence.mjs @@ -235,6 +235,49 @@ async function testSnapshotExportWithoutTombstones() { await db.close(); } +async function testSnapshotProbeExport() { + const db = new BmeDatabase("chat-export-probe", { + dexieClass: globalThis.Dexie, + }); + await db.open(); + + await db.bulkUpsertNodes([ + { + id: "node-probe", + type: "event", + sourceFloor: 4, + archived: false, + updatedAt: Date.now(), + }, + ]); + await db.patchMeta({ + lastProcessedFloor: 6, + extractionCount: 3, + runtimeHistoryState: { + chatId: "chat-export-probe", + lastProcessedAssistantFloor: 6, + extractionCount: 3, + }, + }); + + const probe = await db.exportSnapshotProbe(); + assert.equal(probe.__stBmeProbeOnly, true); + assert.equal(probe.__stBmeTombstonesOmitted, true); + assert.deepEqual(probe.nodes, []); + assert.deepEqual(probe.edges, []); + assert.deepEqual(probe.tombstones, []); + assert.equal(probe.meta.chatId, "chat-export-probe"); + assert.equal(probe.meta.nodeCount, 1); + assert.equal(probe.state.lastProcessedFloor, 6); + assert.equal(probe.state.extractionCount, 3); + assert.equal( + probe.meta.runtimeHistoryState.lastProcessedAssistantFloor, + 6, + ); + + await db.close(); +} + async function testReplaceImportResetsStaleMeta() { const chatId = "chat-replace-reset"; const db = new BmeDatabase(chatId, { dexieClass: globalThis.Dexie }); @@ -577,29 +620,58 @@ async function testGraphSnapshotConverters() { updatedAt: Date.now(), }); + let snapshotDiagnostics = null; const snapshot = buildSnapshotFromGraph(graph, { chatId: "chat-a", revision: 17, + onDiagnostics(snapshotValue) { + snapshotDiagnostics = snapshotValue; + }, }); assert.equal(snapshot.meta.chatId, "chat-a"); assert.equal(snapshot.meta.revision, 17); assert.equal(snapshot.state.lastProcessedFloor, 9); assert.equal(snapshot.state.extractionCount, 4); assert.equal(snapshot.nodes.length, 1); + assert.equal(Number.isFinite(snapshotDiagnostics?.nodesMs), true); + assert.equal(Number.isFinite(snapshotDiagnostics?.edgesMs), true); + assert.equal(Number.isFinite(snapshotDiagnostics?.tombstonesMs), true); + assert.equal(Number.isFinite(snapshotDiagnostics?.stateMs), true); + assert.equal(Number.isFinite(snapshotDiagnostics?.metaMs), true); + assert.equal(Number.isFinite(snapshotDiagnostics?.totalMs), true); + assert.equal(snapshotDiagnostics?.nodeCount, 1); + let hydrateDiagnostics = null; const nextGraph = buildGraphFromSnapshot(snapshot, { chatId: "chat-a", + onDiagnostics(snapshotValue) { + hydrateDiagnostics = snapshotValue; + }, }); + assert.equal(hydrateDiagnostics?.success, true); + assert.equal(Number.isFinite(hydrateDiagnostics?.nodesMs), true); + assert.equal(Number.isFinite(hydrateDiagnostics?.edgesMs), true); + assert.equal(Number.isFinite(hydrateDiagnostics?.runtimeMetaMs), true); + assert.equal(Number.isFinite(hydrateDiagnostics?.stateMs), true); + assert.equal(Number.isFinite(hydrateDiagnostics?.normalizeMs), true); + assert.equal(Number.isFinite(hydrateDiagnostics?.integrityMs), true); + assert.equal(Number.isFinite(hydrateDiagnostics?.totalMs), true); + + let reusedSnapshotDiagnostics = null; const reusedSnapshot = buildSnapshotFromGraph(nextGraph, { chatId: "chat-a", revision: 18, baseSnapshot: snapshot, + onDiagnostics(snapshotValue) { + reusedSnapshotDiagnostics = snapshotValue; + }, }); assert.equal( reusedSnapshot.nodes[0], snapshot.nodes[0], "未变化节点应直接复用 baseSnapshot 记录对象", ); + assert.equal(reusedSnapshotDiagnostics?.reusedNodeCount, 1); nextGraph.nodes[0].updatedAt = Number(nextGraph.nodes[0].updatedAt || 0) + 1; const changedSnapshot = buildSnapshotFromGraph(nextGraph, { chatId: "chat-a", @@ -662,6 +734,7 @@ async function main() { await testTransactionRollback(); await testSnapshotExportImport(); await testSnapshotExportWithoutTombstones(); + await testSnapshotProbeExport(); await testReplaceImportResetsStaleMeta(); await testRevisionMonotonicity(); await testTombstonePrune(); diff --git a/tests/indexeddb-sync.mjs b/tests/indexeddb-sync.mjs index 6c649ac..b373fc8 100644 --- a/tests/indexeddb-sync.mjs +++ b/tests/indexeddb-sync.mjs @@ -298,6 +298,10 @@ async function testUploadPayloadMetaFirstAndDebounce() { assert.equal(uploadResult.uploaded, true); assert.equal(logs.uploadCalls, 1); assert.equal(logs.uploadChunkCalls > 0, true); + assert.equal(Number.isFinite(uploadResult.timings?.exportMs), true); + assert.equal(Number.isFinite(uploadResult.timings?.chunkUploadMs), true); + assert.equal(Number.isFinite(uploadResult.timings?.manifestUploadMs), true); + assert.equal(Number.isFinite(uploadResult.timings?.metaPatchMs), true); const uploadedPayload = logs.uploadedPayloads[0].payload; assert.equal(uploadedPayload.formatVersion, 2); @@ -375,6 +379,10 @@ async function testDownloadImport() { const result = await download("chat-download", runtime); assert.equal(result.downloaded, true); + assert.equal(Number.isFinite(result.timings?.networkMs), true); + assert.equal(Number.isFinite(result.timings?.importMs), true); + assert.equal(Number.isFinite(result.timings?.metaPatchMs), true); + assert.equal(Number.isFinite(result.timings?.hookMs), true); assert.equal(db.lastImportPayload.meta.revision, 12); assert.equal(db.lastImportPayload.nodes[0].id, "remote-node"); assert.equal(db.lastImportPayload.meta.runtimeVectorIndexState.dirty, true); @@ -731,6 +739,10 @@ async function testManualBackupAndRestoreFlow() { const backupResult = await backupToServer("chat-backup-flow", runtime); assert.equal(backupResult.backedUp, true); + assert.equal(Number.isFinite(backupResult.timings?.exportMs), true); + assert.equal(Number.isFinite(backupResult.timings?.uploadMs), true); + assert.equal(Number.isFinite(backupResult.timings?.manifestWriteMs), true); + assert.equal(Number.isFinite(backupResult.timings?.metaPatchMs), true); assert.equal(db.meta.get("syncDirty"), false); assert.ok(Number(db.meta.get("lastBackupUploadedAt")) > 0); assert.ok(String(db.meta.get("lastBackupFilename") || "").startsWith("ST-BME_backup_")); @@ -801,6 +813,12 @@ async function testManualBackupAndRestoreFlow() { const restoreResult = await restoreFromServer("chat-backup-flow", runtime); assert.equal(restoreResult.restored, true); + assert.equal(Number.isFinite(restoreResult.timings?.downloadMs), true); + assert.equal(Number.isFinite(restoreResult.timings?.localExportMs), true); + assert.equal(Number.isFinite(restoreResult.timings?.safetySnapshotMs), true); + assert.equal(Number.isFinite(restoreResult.timings?.importMs), true); + assert.equal(Number.isFinite(restoreResult.timings?.metaPatchMs), true); + assert.equal(Number.isFinite(restoreResult.timings?.hookMs), true); assert.equal(db.snapshot.nodes[0].id, "local-node"); assert.equal(db.snapshot.meta.runtimeBatchJournal.length, 4); assert.equal(db.snapshot.meta.maintenanceJournal.length, 0); @@ -963,6 +981,7 @@ async function testRestoreValidationDoesNotCreateSafetySnapshot() { const restoreResult = await restoreFromServer("chat-no-backup", runtime); assert.equal(restoreResult.restored, false); assert.equal(restoreResult.reason, "not-found"); + assert.equal(Number.isFinite(restoreResult.timings?.downloadMs), true); const safetyStatus = await getRestoreSafetySnapshotStatus( "chat-no-backup", diff --git a/tests/opfs-meta-fast-path.mjs b/tests/opfs-meta-fast-path.mjs index e1c74fc..f18e6ca 100644 --- a/tests/opfs-meta-fast-path.mjs +++ b/tests/opfs-meta-fast-path.mjs @@ -56,12 +56,18 @@ await store.patchMeta({ lastProcessedFloor: 9, extractionCount: 4, }); +const probe = await store.exportSnapshotProbe(); assert.equal( loadSnapshotCalls, 0, "manifest-only meta fast path should not load full snapshot", ); +assert.equal(probe.__stBmeProbeOnly, true); +assert.equal(probe.meta.lastBackupFilename, "after.json"); +assert.equal(probe.meta.nodeCount, 1); +assert.equal(probe.state.lastProcessedFloor, 9); +assert.equal(probe.state.extractionCount, 4); const snapshot = await originalLoadSnapshot(); assert.equal(snapshot.meta.lastBackupFilename, "after.json"); diff --git a/tests/opfs-write-serialization.mjs b/tests/opfs-write-serialization.mjs index 9cf6dff..c6bbd44 100644 --- a/tests/opfs-write-serialization.mjs +++ b/tests/opfs-write-serialization.mjs @@ -261,7 +261,62 @@ async function testGraphLikeDeltaPreservesHistoryFrontier() { ); } +async function testCommitDeltaDiagnosticsSplitWalAndManifestStages() { + const rootDirectory = createMemoryOpfsRoot(); + const store = new OpfsGraphStore("chat-opfs-diagnostics-split", { + rootDirectoryFactory: async () => rootDirectory, + storeMode: BME_GRAPH_LOCAL_STORAGE_MODE_OPFS_PRIMARY, + }); + await store.open(); + + await store.importSnapshot( + { + meta: { revision: 1 }, + state: { lastProcessedFloor: 0, extractionCount: 0 }, + nodes: [], + edges: [], + tombstones: [], + }, + { mode: "replace", preserveRevision: true }, + ); + + const result = await store.commitDelta( + { + upsertNodes: [ + { + id: "diag-node-1", + type: "event", + fields: { title: "diag" }, + archived: false, + updatedAt: 10, + }, + ], + }, + { + reason: "diagnostics-split", + requestedRevision: 2, + markSyncDirty: true, + }, + ); + + assert.equal(Number.isFinite(result.diagnostics?.walSerializeMs), true); + assert.equal(Number.isFinite(result.diagnostics?.walFileWriteMs), true); + assert.equal(Number.isFinite(result.diagnostics?.walWriteMs), true); + assert.equal(Number.isFinite(result.diagnostics?.manifestSerializeMs), true); + assert.equal(Number.isFinite(result.diagnostics?.manifestFileWriteMs), true); + assert.equal(Number.isFinite(result.diagnostics?.manifestWriteMs), true); + assert.equal( + result.diagnostics.walWriteMs >= result.diagnostics.walSerializeMs, + true, + ); + assert.equal( + result.diagnostics.manifestWriteMs >= result.diagnostics.manifestSerializeMs, + true, + ); +} + await testCommitDeltaAndPatchMetaSerialize(); await testImportSnapshotAndClearAllSerialize(); await testGraphLikeDeltaPreservesHistoryFrontier(); +await testCommitDeltaDiagnosticsSplitWalAndManifestStages(); console.log("opfs-write-serialization tests passed"); diff --git a/tests/perf/persist-load-bench.mjs b/tests/perf/persist-load-bench.mjs new file mode 100644 index 0000000..a33f5c0 --- /dev/null +++ b/tests/perf/persist-load-bench.mjs @@ -0,0 +1,326 @@ +import { performance } from "node:perf_hooks"; + +import { + buildGraphFromSnapshot, + buildPersistDelta, + buildSnapshotFromGraph, +} from "../../sync/bme-db.js"; +import { + BME_GRAPH_LOCAL_STORAGE_MODE_OPFS_PRIMARY, + OpfsGraphStore, +} from "../../sync/bme-opfs-store.js"; +import { createMemoryOpfsRoot } from "../helpers/memory-opfs.mjs"; + +const RUNS = 4; +const SIZE_PRESETS = [ + { label: "M", seed: 17, nodeCount: 1200, edgeCount: 3600, churn: 0.08 }, + { label: "L", seed: 29, nodeCount: 3600, edgeCount: 10800, churn: 0.1 }, + { label: "XL", seed: 43, nodeCount: 7200, edgeCount: 21600, churn: 0.12 }, +]; + +function summarize(values = []) { + if (!values.length) { + return { avg: 0, p95: 0, min: 0, max: 0 }; + } + const sorted = [...values].sort((a, b) => a - b); + const sum = sorted.reduce((acc, value) => acc + value, 0); + const p95Index = Math.min(sorted.length - 1, Math.floor(sorted.length * 0.95)); + return { + avg: sum / sorted.length, + p95: sorted[p95Index], + min: sorted[0], + max: sorted[sorted.length - 1], + }; +} + +function formatSummary(label, values = []) { + const summary = summarize(values); + return `${label} avg=${summary.avg.toFixed(2)}ms p95=${summary.p95.toFixed(2)}ms min=${summary.min.toFixed(2)}ms max=${summary.max.toFixed(2)}ms`; +} + +function createRandom(seed = 1) { + let state = seed >>> 0; + return () => { + state = (state * 1664525 + 1013904223) >>> 0; + return state / 0xffffffff; + }; +} + +function buildRuntimeGraph(seed = 1, nodeCount = 100, edgeCount = 200, chatId = "bench-chat") { + const rand = createRandom(seed); + const nodes = []; + const edges = []; + for (let index = 0; index < nodeCount; index += 1) { + nodes.push({ + id: `node-${index}`, + type: "event", + updatedAt: 1000 + index, + archived: false, + sourceFloor: index, + fields: { + title: `Node ${index}`, + text: `node-${index}-${Math.floor(rand() * 100000)}`, + }, + }); + } + for (let index = 0; index < edgeCount; index += 1) { + const fromIndex = Math.floor(rand() * nodeCount); + let toIndex = Math.floor(rand() * nodeCount); + if (toIndex === fromIndex) { + toIndex = (toIndex + 1) % nodeCount; + } + edges.push({ + id: `edge-${index}`, + fromId: `node-${fromIndex}`, + toId: `node-${toIndex}`, + relation: "related", + strength: rand(), + updatedAt: 2000 + index, + }); + } + return { + version: 1, + nodes, + edges, + historyState: { + chatId, + lastProcessedAssistantFloor: Math.max(0, Math.floor(nodeCount / 12)), + extractionCount: Math.max(1, Math.floor(nodeCount / 40)), + processedMessageHashes: {}, + processedMessageHashVersion: 1, + processedMessageHashesNeedRefresh: false, + recentRecallOwnerKeys: [], + activeRecallOwnerKey: "", + activeRegion: "", + activeRegionSource: "", + activeStorySegmentId: "", + activeStoryTimeLabel: "", + activeStoryTimeSource: "", + lastBatchStatus: null, + lastMutationSource: "bench", + lastExtractedRegion: "", + lastExtractedStorySegmentId: "", + activeCharacterPovOwner: "", + activeUserPovOwner: "", + }, + vectorIndexState: { + chatId, + collectionId: "", + hashToNodeId: {}, + nodeToHash: {}, + replayRequiredNodeIds: [], + dirty: false, + dirtyReason: "", + pendingRepairFromFloor: null, + lastIntegrityIssue: null, + lastStats: { + nodesIndexed: 0, + updatedAt: 0, + }, + }, + knowledgeState: { + owners: {}, + activeOwnerKey: "", + }, + regionState: { + activeRegion: "", + knownRegions: {}, + manualActiveRegion: "", + }, + timelineState: { + activeSegmentId: "", + manualActiveSegmentId: "", + segments: [], + }, + summaryState: { + updatedAt: 0, + entries: [], + }, + batchJournal: [], + maintenanceJournal: [], + lastRecallResult: null, + lastProcessedSeq: Math.max(0, Math.floor(nodeCount / 12)), + }; +} + +function mutateRuntimeGraph(baseGraph, seed = 1, churn = 0.1) { + const rand = createRandom(seed); + const nextGraph = structuredClone(baseGraph); + const mutateNodeCount = Math.max(1, Math.floor(nextGraph.nodes.length * churn)); + const mutateEdgeCount = Math.max(1, Math.floor(nextGraph.edges.length * churn * 0.5)); + for (let index = 0; index < mutateNodeCount; index += 1) { + const nodeIndex = Math.floor(rand() * nextGraph.nodes.length); + const node = nextGraph.nodes[nodeIndex]; + node.updatedAt += 100 + index; + node.fields.text = `${node.fields.text}-mut-${index}`; + } + for (let index = 0; index < mutateEdgeCount; index += 1) { + const edgeIndex = Math.floor(rand() * nextGraph.edges.length); + const edge = nextGraph.edges[edgeIndex]; + edge.updatedAt += 80 + index; + edge.strength = rand(); + } + const addNodeCount = Math.max(1, Math.floor(nextGraph.nodes.length * churn * 0.12)); + const baseNodeId = nextGraph.nodes.length; + for (let index = 0; index < addNodeCount; index += 1) { + nextGraph.nodes.push({ + id: `node-new-${baseNodeId + index}`, + type: "event", + updatedAt: 5000 + index, + archived: false, + sourceFloor: baseNodeId + index, + fields: { + title: `Node new ${index}`, + text: `new-node-${index}`, + }, + }); + } + const deleteEdgeCount = Math.max(1, Math.floor(nextGraph.edges.length * churn * 0.08)); + nextGraph.edges.splice(0, deleteEdgeCount); + nextGraph.historyState.lastProcessedAssistantFloor += 1; + nextGraph.historyState.extractionCount += 1; + nextGraph.lastProcessedSeq = nextGraph.historyState.lastProcessedAssistantFloor; + nextGraph.summaryState.updatedAt += 1; + return nextGraph; +} + +function buildBenchPair({ label, seed, nodeCount, edgeCount, churn }) { + const chatId = `bench-${label.toLowerCase()}`; + const beforeGraph = buildRuntimeGraph(seed, nodeCount, edgeCount, chatId); + const afterGraph = mutateRuntimeGraph(beforeGraph, seed + 101, churn); + return { + label, + chatId, + beforeGraph, + afterGraph, + }; +} + +function measureSnapshotBuild(graph, options) { + let diagnostics = null; + const startedAt = performance.now(); + const snapshot = buildSnapshotFromGraph(graph, { + ...options, + onDiagnostics(snapshotValue) { + diagnostics = snapshotValue; + }, + }); + return { + elapsedMs: performance.now() - startedAt, + snapshot, + diagnostics, + }; +} + +function measureHydrate(snapshot, chatId) { + let diagnostics = null; + const startedAt = performance.now(); + buildGraphFromSnapshot(snapshot, { + chatId, + onDiagnostics(snapshotValue) { + diagnostics = snapshotValue; + }, + }); + return { + elapsedMs: performance.now() - startedAt, + diagnostics, + }; +} + +async function measureOpfsCommit(baseSnapshot, afterSnapshot, delta, chatId) { + const rootDirectory = createMemoryOpfsRoot(); + const store = new OpfsGraphStore(chatId, { + rootDirectoryFactory: async () => rootDirectory, + storeMode: BME_GRAPH_LOCAL_STORAGE_MODE_OPFS_PRIMARY, + }); + await store.open(); + await store.importSnapshot(baseSnapshot, { + mode: "replace", + preserveRevision: true, + markSyncDirty: false, + }); + const startedAt = performance.now(); + const result = await store.commitDelta(delta, { + reason: "bench-commit", + requestedRevision: Number(afterSnapshot?.meta?.revision || 0), + markSyncDirty: true, + committedSnapshot: afterSnapshot, + }); + const elapsedMs = performance.now() - startedAt; + await store.close(); + return { + elapsedMs, + diagnostics: result?.diagnostics || {}, + }; +} + +async function runPreset(preset) { + const snapshotBuildSamples = []; + const hydrateSamples = []; + const opfsCommitSamples = []; + const snapshotNodesSamples = []; + const hydrateRuntimeMetaSamples = []; + const walFileWriteSamples = []; + const manifestFileWriteSamples = []; + + for (let run = 0; run < RUNS; run += 1) { + const pair = buildBenchPair({ + ...preset, + seed: preset.seed + run * 17, + }); + const beforeSnapshotResult = measureSnapshotBuild(pair.beforeGraph, { + chatId: pair.chatId, + revision: 1, + }); + const afterSnapshotResult = measureSnapshotBuild(pair.afterGraph, { + chatId: pair.chatId, + revision: 2, + baseSnapshot: beforeSnapshotResult.snapshot, + }); + const delta = buildPersistDelta( + beforeSnapshotResult.snapshot, + afterSnapshotResult.snapshot, + { useNativeDelta: false }, + ); + const hydrateResult = measureHydrate(afterSnapshotResult.snapshot, pair.chatId); + const opfsCommitResult = await measureOpfsCommit( + beforeSnapshotResult.snapshot, + afterSnapshotResult.snapshot, + delta, + pair.chatId, + ); + + snapshotBuildSamples.push(afterSnapshotResult.elapsedMs); + hydrateSamples.push(hydrateResult.elapsedMs); + opfsCommitSamples.push(opfsCommitResult.elapsedMs); + snapshotNodesSamples.push(Number(afterSnapshotResult.diagnostics?.nodesMs || 0)); + hydrateRuntimeMetaSamples.push(Number(hydrateResult.diagnostics?.runtimeMetaMs || 0)); + walFileWriteSamples.push(Number(opfsCommitResult.diagnostics?.walFileWriteMs || 0)); + manifestFileWriteSamples.push( + Number(opfsCommitResult.diagnostics?.manifestFileWriteMs || 0), + ); + } + + console.log(`\n[ST-BME][persist-load-bench] ${preset.label}`); + console.log( + formatSummary("snapshot-build", snapshotBuildSamples), + `nodesPhaseP95=${summarize(snapshotNodesSamples).p95.toFixed(2)}ms`, + ); + console.log( + formatSummary("hydrate", hydrateSamples), + `runtimeMetaP95=${summarize(hydrateRuntimeMetaSamples).p95.toFixed(2)}ms`, + ); + console.log( + formatSummary("opfs-commit", opfsCommitSamples), + `walFileP95=${summarize(walFileWriteSamples).p95.toFixed(2)}ms`, + `manifestFileP95=${summarize(manifestFileWriteSamples).p95.toFixed(2)}ms`, + ); +} + +async function main() { + for (const preset of SIZE_PRESETS) { + await runPreset(preset); + } +} + +await main(); diff --git a/ui/panel.js b/ui/panel.js index 7aa4b29..0bd708b 100644 --- a/ui/panel.js +++ b/ui/panel.js @@ -1564,12 +1564,22 @@ function _formatPersistCommitBreakdownText(diagnostics = null) { snapshot.commitManifestReadMs ? `manifest-read ${_formatDurationMs(snapshot.commitManifestReadMs)}` : "", - snapshot.commitWalWriteMs - ? `wal ${_formatDurationMs(snapshot.commitWalWriteMs)}` + snapshot.commitWalSerializeMs + ? `wal-serialize ${_formatDurationMs(snapshot.commitWalSerializeMs)}` : "", - snapshot.commitManifestWriteMs - ? `manifest-write ${_formatDurationMs(snapshot.commitManifestWriteMs)}` + snapshot.commitWalFileWriteMs + ? `wal-file ${_formatDurationMs(snapshot.commitWalFileWriteMs)}` + : snapshot.commitWalWriteMs + ? `wal ${_formatDurationMs(snapshot.commitWalWriteMs)}` + : "", + snapshot.commitManifestSerializeMs + ? `manifest-serialize ${_formatDurationMs(snapshot.commitManifestSerializeMs)}` : "", + snapshot.commitManifestFileWriteMs + ? `manifest-file ${_formatDurationMs(snapshot.commitManifestFileWriteMs)}` + : snapshot.commitManifestWriteMs + ? `manifest-write ${_formatDurationMs(snapshot.commitManifestWriteMs)}` + : "", snapshot.commitCacheApplyMs ? `cache ${_formatDurationMs(snapshot.commitCacheApplyMs)}` : "", @@ -1577,6 +1587,70 @@ function _formatPersistCommitBreakdownText(diagnostics = null) { return parts.join(" · ") || "—"; } +function _formatPersistSnapshotBuildBreakdownText(diagnostics = null) { + const snapshot = _readPersistenceDiagnosticObject(diagnostics); + if (!snapshot) return "—"; + const parts = [ + snapshot.snapshotNodesMs + ? `nodes ${_formatDurationMs(snapshot.snapshotNodesMs)}` + : "", + snapshot.snapshotEdgesMs + ? `edges ${_formatDurationMs(snapshot.snapshotEdgesMs)}` + : "", + snapshot.snapshotTombstonesMs + ? `tombstones ${_formatDurationMs(snapshot.snapshotTombstonesMs)}` + : "", + snapshot.snapshotStateMs + ? `state ${_formatDurationMs(snapshot.snapshotStateMs)}` + : "", + snapshot.snapshotMetaMs + ? `meta ${_formatDurationMs(snapshot.snapshotMetaMs)}` + : "", + ].filter(Boolean); + return parts.join(" · ") || "—"; +} + +function _formatLoadHydrateBreakdownText(diagnostics = null) { + const snapshot = _readPersistenceDiagnosticObject(diagnostics); + if (!snapshot) return "—"; + const parts = [ + snapshot.hydrateNodesMs + ? `nodes ${_formatDurationMs(snapshot.hydrateNodesMs)}` + : "", + snapshot.hydrateEdgesMs + ? `edges ${_formatDurationMs(snapshot.hydrateEdgesMs)}` + : "", + snapshot.hydrateRuntimeMetaMs + ? `meta ${_formatDurationMs(snapshot.hydrateRuntimeMetaMs)}` + : "", + snapshot.hydrateStateMs + ? `state ${_formatDurationMs(snapshot.hydrateStateMs)}` + : "", + snapshot.hydrateNormalizeMs + ? `normalize ${_formatDurationMs(snapshot.hydrateNormalizeMs)}` + : "", + snapshot.hydrateIntegrityMs + ? `integrity ${_formatDurationMs(snapshot.hydrateIntegrityMs)}` + : "", + ].filter(Boolean); + return parts.join(" · ") || "—"; +} + +function _formatPersistObservabilityText(diagnostics = null) { + const snapshot = _readPersistenceDiagnosticObject(diagnostics); + if (!snapshot) return "—"; + const parts = []; + const pathKey = String(snapshot.pathKey || snapshot.path || "").trim(); + const reasonKey = String(snapshot.reasonKey || snapshot.saveReason || "").trim(); + const pathCount = Number(snapshot.pathSampleCount || 0); + const reasonCount = Number(snapshot.reasonSampleCount || 0); + if (pathKey) parts.push(`path ${pathKey}`); + if (pathCount > 0) parts.push(`${pathCount} samples`); + if (reasonKey) parts.push(`reason ${reasonKey}`); + if (reasonCount > 0) parts.push(`${reasonCount} reason-hits`); + return parts.join(" · ") || "—"; +} + function _formatPersistCommitBytesText(diagnostics = null) { const snapshot = _readPersistenceDiagnosticObject(diagnostics); if (!snapshot) return "—"; @@ -1616,6 +1690,7 @@ function _buildLoadDiagnosticRows(loadDiagnostics = null) { ["导出快照", _formatDurationMs(diagnostics.exportSnapshotMs)], ["前置（除导出）", _formatDurationMs(diagnostics.preApplyOtherMs)], ["Hydrate", _formatDurationMs(diagnostics.hydrateMs)], + ["Hydrate 细分", _formatLoadHydrateBreakdownText(diagnostics)], ["Apply 调用", _formatDurationMs(diagnostics.applyInvokeMs)], ["Apply 运行", _formatDurationMs(diagnostics.applyRuntimeMs)], ["Load 未归因", _formatDurationMs(diagnostics.untrackedMs)], @@ -1659,6 +1734,7 @@ function _buildPersistDeltaDiagnosticRows(persistDelta = null) { ["构建耗时", _formatDurationMs(diagnostics.buildMs)], ["Base 快照读取", _formatDurationMs(diagnostics.baseSnapshotReadMs)], ["图谱快照构建", _formatDurationMs(diagnostics.snapshotBuildMs)], + ["快照构建细分", _formatPersistSnapshotBuildBreakdownText(diagnostics)], [ "Prepare / Native", `${_formatDurationMs(diagnostics.prepareMs)} / ${_formatDurationMs(diagnostics.nativeAttemptMs)}`, @@ -1671,6 +1747,7 @@ function _buildPersistDeltaDiagnosticRows(persistDelta = null) { ["Commit 排队 / 提交", commitPhaseText], ["Commit 细分", commitBreakdownText], ["Commit Payload", commitBytesText], + ["样本聚合", _formatPersistObservabilityText(diagnostics)], ["Preload", String(diagnostics.preloadStatus || "—")], ["Native 来源", String(diagnostics.moduleSource || "—")], ["Fallback 原因", String(diagnostics.fallbackReason || "—")], diff --git a/ui/ui-status.js b/ui/ui-status.js index debedd3..ccf295a 100644 --- a/ui/ui-status.js +++ b/ui/ui-status.js @@ -125,6 +125,16 @@ export function createGraphPersistenceState() { lastSyncError: "", dualWriteLastResult: null, persistDelta: null, + persistObservability: { + totalSamples: 0, + byPath: {}, + byReason: {}, + byPathReason: {}, + lastPathKey: "", + lastReasonKey: "", + lastPathReasonKey: "", + lastRecordedAt: "", + }, loadDiagnostics: null, updatedAt: new Date().toISOString(), };