@@ -590,7 +590,8 @@ rows exist". |
||
| 590 | 590 |
| 2026-06-04 | `1ba6c38` | Hash delta compact archives in recorded order. | Small-delta follow-up completed in `24.0s` with `127/127` complete, `0` degraded, `CaptureModes: unchangedDelta=124, delta=3, initialImport=0`, and `DeltaEvents: 13`. This finally validated the remaining bottleneck: Heart Rate still spent `5.7s` processing only `6` events, Active Energy spent `2.1s` for `5` events, and Basal Energy spent `1.8s` for `2` events. The delta rebuild no longer builds a full UUID record map, but it still collected every fingerprint into a large array and sorted it for the per-type hash. Delta rebuild now uses the same recorded-order `TypeHashBuilder` strategy as initial import, avoiding the all-record fingerprint array and sort. | |
| 591 | 591 |
| 2026-06-04 | `d4de48c` | Copy unchanged daily aggregates inside SQLite. | First small-delta run before this commit completed in `23.6s` with `127/127` complete, `0` degraded, `CaptureModes: unchangedDelta=120, delta=7`, and `DeltaEvents: 11`. The hash change helped processing (`9.6s -> 8.1s`; Heart Rate `5.7s -> 4.2s`), but finalization stayed high (`11.4s`, Heart Rate `4.8s`). Changed daily aggregates were copying all previous daily rows through Swift before replacing affected buckets. This commit moved unchanged daily aggregate copying to SQLite `INSERT ... SELECT`, while affected buckets remain recalculated. Follow-up report completed in `21.1s` with `127/127` complete, `0` degraded, `CaptureModes: unchangedDelta=123, delta=4`, and `DeltaEvents: 50`. `SummedFinalizeElapsed` improved `11.4s -> 9.3s` and wall clock improved `23.6s -> 21.1s`; however Heart Rate finalize was still `5.0s` with `4` events, so this helped overall finalize cost but did not remove the high-volume changed-type floor. | |
| 592 | 592 |
| 2026-06-04 | `c9091de` | Include build identity in diagnostic reports. | The latest diagnostic report only included `App Version: 1.0(1)` near the end and did not include a commit/build source identifier. This makes it too easy to compare reports from the wrong installed binary. Diagnostics now emit `appVersion`, `buildFingerprint`, `sourceCommit`, and `sourceDirty` in `OPERATION METADATA`. `buildFingerprint` is derived from the installed executable and should change when a different binary is installed; `sourceCommit/sourceDirty` remain available for builds that inject those Info.plist keys. Expected signal: future pasted reports have enough build identity to detect wrong-version reports immediately. | |
| 593 |
-| 2026-06-04 | pending | Avoid summary full scans when delta safely replaces extremes. | Follow-up after `d4de48c` still showed `SummedFinalizeElapsed: 9.3s`, with Heart Rate finalize at `5.0s` despite only `4` Heart Rate delta events. `markVerification` already tries to update type summaries incrementally, but it fell back to a full visible-row aggregate scan whenever a removed row matched the previous earliest/latest/max, even if the same delta added a row that safely preserved or extended that extreme. The fallback is now narrower: full scan is still used when an extreme becomes unknown, but not when added rows replace the removed earliest/latest/max with an equivalent or stronger value. Expected signal: on repeated full-profile captures with small recent deltas, `SummedFinalizeElapsed` and high-volume type finalize times, especially Heart Rate, should drop when deltas replace recent/latest rows. Correctness is covered by synthetic SQLite archive tests for replaced latest/max and removed-latest-without-replacement cases. | |
|
| 593 |
+| 2026-06-04 | `7e3b997` | Avoid summary full scans when delta safely replaces extremes. | Follow-up after `d4de48c` still showed `SummedFinalizeElapsed: 9.3s`, with Heart Rate finalize at `5.0s` despite only `4` Heart Rate delta events. `markVerification` already tries to update type summaries incrementally, but it fell back to a full visible-row aggregate scan whenever a removed row matched the previous earliest/latest/max, even if the same delta added a row that safely preserved or extended that extreme. The fallback is now narrower: full scan is still used when an extreme becomes unknown, but not when added rows replace the removed earliest/latest/max with an equivalent or stronger value. Follow-up report with `reportSchemaVersion: 3` and `buildFingerprint: 1.0(1)-1780603665-92064` completed in `21.0s`, with `127/127` complete, `CaptureModes: unchangedDelta=121, delta=6`, and `DeltaEvents: 20`. This was effectively flat versus the `d4de48c` report: wall `21.1s -> 21.0s`, processing `7.8s -> 7.4s`, finalize `9.3s -> 9.4s`, and Heart Rate finalize `5.0s -> 4.8s` while Heart Rate had `7` delta events. Conclusion: this optimization did not materially move the bottleneck; either the safe-extreme case did not trigger or type-summary fallback is no longer the dominant finalize cost. | |
|
| 594 |
+| 2026-06-04 | pending | Add archive finalization phase timings to diagnostics. | The post-`7e3b997` report proves the top-level `finalizeElapsed` bucket is too opaque for the next optimization. Diagnostics now split finalization into event-count/previous-summary lookup, type-summary work, daily-aggregate work, observation-type-run update, and residual other time. Expected signal: the next report should show whether Heart Rate's `~4.8s` finalize cost is mostly daily aggregate replacement, type summary work, event lookup, or unaccounted SQLite/transaction overhead. Use that result before attempting another finalize optimization. | |
|
| 594 | 595 |
|
| 595 | 596 |
## Current Diagnosis |
| 596 | 597 |
|
@@ -694,6 +695,11 @@ The likely bottleneck is per-row SQLite work: |
||
| 694 | 695 |
newer/larger replacement no longer needs a full visible aggregate scan. The |
| 695 | 696 |
archive still falls back to the full scan when a removed earliest/latest/max |
| 696 | 697 |
leaves the new extreme genuinely unknown. |
| 698 |
+- The first post-extreme-fallback report was flat: total finalize stayed around |
|
| 699 |
+ `9.4s` and Heart Rate finalize stayed around `4.8s`. Do not continue guessing |
|
| 700 |
+ inside finalization without phase timings; the diagnostic report now needs to |
|
| 701 |
+ show whether the remaining time is type-summary, daily-aggregate, |
|
| 702 |
+ event-count, run-update, or other overhead. |
|
| 697 | 703 |
|
| 698 | 704 |
## Open Issues / Observations |
| 699 | 705 |
|
@@ -752,28 +758,31 @@ Prioritize experiments in this order: |
||
| 752 | 758 |
identity unless the build provenance is otherwise certain. `sourceCommit` |
| 753 | 759 |
and `sourceDirty` are useful when present, but may be `unknown` for normal |
| 754 | 760 |
Xcode test installs. |
| 755 |
-8. Run a repeated full-profile capture after narrowing incremental summary |
|
| 756 |
- fallback. Compare `SummedFinalizeElapsed` and Heart Rate finalize against the |
|
| 757 |
- `9.3s` total finalize / `5.0s` Heart Rate finalize report after `d4de48c`. |
|
| 758 |
- This optimization should help only when changed high-volume metrics replace |
|
| 759 |
- extremes safely; if Heart Rate finalize remains around `5s`, the remaining |
|
| 760 |
- cost is likely daily-bucket replacement or compact archive processing rather |
|
| 761 |
- than type summary full-scan fallback. |
|
| 762 |
-9. Investigate full-profile empty anchored-query cost for zero-count types. |
|
| 761 |
+8. Run a repeated full-profile capture with finalization phase timings. Compare |
|
| 762 |
+ `SummedFinalizeTypeSummaryElapsed`, `SummedFinalizeDailyAggregateElapsed`, |
|
| 763 |
+ `SummedFinalizeEventCountElapsed`, `SummedFinalizeRunUpdateElapsed`, and |
|
| 764 |
+ `SummedFinalizeOtherElapsed`, plus the same per-metric fields for Heart Rate. |
|
| 765 |
+ This determines the next real finalize optimization target. |
|
| 766 |
+9. Investigate replacing legacy compact `recordArchiveData` delta rebuild with |
|
| 767 |
+ a SQLite-derived capture-state/hash path. The current repeated full-profile |
|
| 768 |
+ reports still spend about `4s` processing Heart Rate for tiny deltas because |
|
| 769 |
+ the Swift compact archive is decoded and rewritten for the whole 900k-row |
|
| 770 |
+ type. |
|
| 771 |
+10. Investigate full-profile empty anchored-query cost for zero-count types. |
|
| 763 | 772 |
Compare slow empty types across reports before changing behavior; any skip or |
| 764 | 773 |
lower-frequency strategy must preserve the promise that full authorized |
| 765 | 774 |
backup can notice newly appearing data. |
| 766 |
-10. Run a non-chain-start/full-scan benchmark after skipping unchanged `verified` events and fast-pathing already-open visibility ranges. Compare `SummedInsertElapsed`, `Heart Rate insertElapsed`, `Steps insertElapsed`, and `Walking + Running Distance insertElapsed`. |
|
| 767 |
-11. Reduce any remaining per-sample SQLite writes for unchanged existing samples during non-chain-start full scans. |
|
| 768 |
-12. Profile whether index maintenance dominates first-import insert cost. |
|
| 769 |
-13. Consider a guarded bulk-import mode for first observations: |
|
| 775 |
+11. Run a non-chain-start/full-scan benchmark after skipping unchanged `verified` events and fast-pathing already-open visibility ranges. Compare `SummedInsertElapsed`, `Heart Rate insertElapsed`, `Steps insertElapsed`, and `Walking + Running Distance insertElapsed`. |
|
| 776 |
+12. Reduce any remaining per-sample SQLite writes for unchanged existing samples during non-chain-start full scans. |
|
| 777 |
+13. Profile whether index maintenance dominates first-import insert cost. |
|
| 778 |
+14. Consider a guarded bulk-import mode for first observations: |
|
| 770 | 779 |
- keep archive semantics unchanged; |
| 771 | 780 |
- only relax work that can be safely reconstructed or validated; |
| 772 | 781 |
- re-enable normal idempotent paths for incremental observations. |
| 773 |
-14. Run a fresh first-import benchmark after the unused-index removal and compare `SummedInsertElapsed`, `Heart Rate insertElapsed`, and `Active Energy insertElapsed`. |
|
| 774 |
-15. Investigate whether first-import-only deferred index creation or temporary staging tables can reduce `samples` / `sample_versions` / `sample_observation_events` write cost without weakening final archive integrity. |
|
| 775 |
-16. Revisit adaptive page sizes only after SQLite write-path costs are reduced. |
|
| 776 |
-17. Revisit background / scheduled collection once initial import can finish reliably and post-import UI recovery is bounded. |
|
| 782 |
+15. Run a fresh first-import benchmark after the unused-index removal and compare `SummedInsertElapsed`, `Heart Rate insertElapsed`, and `Active Energy insertElapsed`. |
|
| 783 |
+16. Investigate whether first-import-only deferred index creation or temporary staging tables can reduce `samples` / `sample_versions` / `sample_observation_events` write cost without weakening final archive integrity. |
|
| 784 |
+17. Revisit adaptive page sizes only after SQLite write-path costs are reduced. |
|
| 785 |
+18. Revisit background / scheduled collection once initial import can finish reliably and post-import UI recovery is bounded. |
|
| 777 | 786 |
|
| 778 | 787 |
## Verification Checklist For Each Optimization |
| 779 | 788 |
|
@@ -1154,7 +1154,7 @@ final class HealthKitService {
|
||
| 1154 | 1154 |
earliestDate: earliestDate, |
| 1155 | 1155 |
latestDate: latestDate |
| 1156 | 1156 |
) {
|
| 1157 |
- captureTimings.finalizeElapsedSeconds += try await finalizeUnchangedArchiveVerification( |
|
| 1157 |
+ captureTimings.addFinalization(try await finalizeUnchangedArchiveVerification( |
|
| 1158 | 1158 |
sampleType: sampleType, |
| 1159 | 1159 |
typeIdentifier: typeIdentifier, |
| 1160 | 1160 |
recordCount: unchanged.totalCount, |
@@ -1162,7 +1162,7 @@ final class HealthKitService {
|
||
| 1162 | 1162 |
processedEventCount: processedEventCount, |
| 1163 | 1163 |
archiveObservationID: archiveObservationID, |
| 1164 | 1164 |
progress: progress |
| 1165 |
- ) |
|
| 1165 |
+ )) |
|
| 1166 | 1166 |
progress?.updateBlockProgress( |
| 1167 | 1167 |
typeIdentifier, |
| 1168 | 1168 |
detail: "No HealthKit delta", |
@@ -1300,7 +1300,7 @@ final class HealthKitService {
|
||
| 1300 | 1300 |
) |
| 1301 | 1301 |
captureTimings.processingElapsedSeconds += Date().timeIntervalSince(archiveRebuildStartedAt) |
| 1302 | 1302 |
|
| 1303 |
- captureTimings.finalizeElapsedSeconds += try await finalizeArchiveVerification( |
|
| 1303 |
+ captureTimings.addFinalization(try await finalizeArchiveVerification( |
|
| 1304 | 1304 |
sampleType: sampleType, |
| 1305 | 1305 |
typeIdentifier: typeIdentifier, |
| 1306 | 1306 |
recordCount: rebuiltArchive.count, |
@@ -1308,7 +1308,7 @@ final class HealthKitService {
|
||
| 1308 | 1308 |
processedEventCount: processedEventCount, |
| 1309 | 1309 |
archiveObservationID: archiveObservationID, |
| 1310 | 1310 |
progress: progress |
| 1311 |
- ) |
|
| 1311 |
+ )) |
|
| 1312 | 1312 |
|
| 1313 | 1313 |
progress?.updateBlockProgress( |
| 1314 | 1314 |
typeIdentifier, |
@@ -1583,7 +1583,7 @@ final class HealthKitService {
|
||
| 1583 | 1583 |
) |
| 1584 | 1584 |
) |
| 1585 | 1585 |
|
| 1586 |
- captureTimings.finalizeElapsedSeconds += try await finalizeArchiveVerification( |
|
| 1586 |
+ captureTimings.addFinalization(try await finalizeArchiveVerification( |
|
| 1587 | 1587 |
sampleType: sampleType, |
| 1588 | 1588 |
typeIdentifier: typeIdentifier, |
| 1589 | 1589 |
recordCount: recordCount, |
@@ -1591,7 +1591,7 @@ final class HealthKitService {
|
||
| 1591 | 1591 |
processedEventCount: processedEventCount, |
| 1592 | 1592 |
archiveObservationID: archiveObservationID, |
| 1593 | 1593 |
progress: progress |
| 1594 |
- ) |
|
| 1594 |
+ )) |
|
| 1595 | 1595 |
|
| 1596 | 1596 |
guard recordCount > 0 || anchor != nil else {
|
| 1597 | 1597 |
return SampleDistribution( |
@@ -1679,7 +1679,7 @@ final class HealthKitService {
|
||
| 1679 | 1679 |
processedEventCount: Int, |
| 1680 | 1680 |
archiveObservationID: Int64, |
| 1681 | 1681 |
progress: SnapshotFetchProgress? |
| 1682 |
- ) async throws -> TimeInterval {
|
|
| 1682 |
+ ) async throws -> HealthArchiveFinalizationBreakdown {
|
|
| 1683 | 1683 |
try await finalizeArchiveVerification( |
| 1684 | 1684 |
sampleType: sampleType, |
| 1685 | 1685 |
typeIdentifier: typeIdentifier, |
@@ -1706,8 +1706,8 @@ final class HealthKitService {
|
||
| 1706 | 1706 |
processedEventCount: Int, |
| 1707 | 1707 |
archiveObservationID: Int64, |
| 1708 | 1708 |
progress: SnapshotFetchProgress?, |
| 1709 |
- markVerification: (() async throws -> Void)? = nil |
|
| 1710 |
- ) async throws -> TimeInterval {
|
|
| 1709 |
+ markVerification: (() async throws -> HealthArchiveFinalizationBreakdown)? = nil |
|
| 1710 |
+ ) async throws -> HealthArchiveFinalizationBreakdown {
|
|
| 1711 | 1711 |
let elapsedBeforeFinalize = Date().timeIntervalSince(progressStarted) |
| 1712 | 1712 |
progress?.updateBlockProgress( |
| 1713 | 1713 |
typeIdentifier, |
@@ -1721,16 +1721,19 @@ final class HealthKitService {
|
||
| 1721 | 1721 |
) |
| 1722 | 1722 |
|
| 1723 | 1723 |
let verificationStartedAt = Date() |
| 1724 |
+ let breakdown: HealthArchiveFinalizationBreakdown |
|
| 1724 | 1725 |
if let markVerification {
|
| 1725 |
- try await markVerification() |
|
| 1726 |
+ breakdown = try await markVerification() |
|
| 1726 | 1727 |
} else {
|
| 1727 |
- try await archiveStore.markVerification( |
|
| 1728 |
+ breakdown = try await archiveStore.markVerification( |
|
| 1728 | 1729 |
sampleType: sampleType, |
| 1729 | 1730 |
verifiedAt: Date(), |
| 1730 | 1731 |
observationID: archiveObservationID |
| 1731 | 1732 |
) |
| 1732 | 1733 |
} |
| 1733 | 1734 |
let finalizeElapsed = Date().timeIntervalSince(verificationStartedAt) |
| 1735 |
+ var normalizedBreakdown = breakdown |
|
| 1736 |
+ normalizedBreakdown.totalElapsedSeconds = finalizeElapsed |
|
| 1734 | 1737 |
|
| 1735 | 1738 |
let elapsedAfterFinalize = Date().timeIntervalSince(progressStarted) |
| 1736 | 1739 |
progress?.updateBlockProgress( |
@@ -1744,7 +1747,7 @@ final class HealthKitService {
|
||
| 1744 | 1747 |
) |
| 1745 | 1748 |
) |
| 1746 | 1749 |
|
| 1747 |
- return finalizeElapsed |
|
| 1750 |
+ return normalizedBreakdown |
|
| 1748 | 1751 |
} |
| 1749 | 1752 |
|
| 1750 | 1753 |
private static func pageProgressDetail( |
@@ -2961,15 +2964,34 @@ private struct DistributionCaptureTimings: Sendable, Equatable {
|
||
| 2961 | 2964 |
var processingElapsedSeconds: TimeInterval = 0 |
| 2962 | 2965 |
var insertElapsedSeconds: TimeInterval = 0 |
| 2963 | 2966 |
var finalizeElapsedSeconds: TimeInterval = 0 |
| 2967 |
+ var finalizeEventCountElapsedSeconds: TimeInterval = 0 |
|
| 2968 |
+ var finalizeTypeSummaryElapsedSeconds: TimeInterval = 0 |
|
| 2969 |
+ var finalizeDailyAggregateElapsedSeconds: TimeInterval = 0 |
|
| 2970 |
+ var finalizeRunUpdateElapsedSeconds: TimeInterval = 0 |
|
| 2971 |
+ var finalizeOtherElapsedSeconds: TimeInterval = 0 |
|
| 2964 | 2972 |
|
| 2965 | 2973 |
static let zero = DistributionCaptureTimings() |
| 2966 | 2974 |
|
| 2975 |
+ mutating func addFinalization(_ breakdown: HealthArchiveFinalizationBreakdown) {
|
|
| 2976 |
+ finalizeElapsedSeconds += breakdown.totalElapsedSeconds |
|
| 2977 |
+ finalizeEventCountElapsedSeconds += breakdown.eventCountElapsedSeconds |
|
| 2978 |
+ finalizeTypeSummaryElapsedSeconds += breakdown.typeSummaryElapsedSeconds |
|
| 2979 |
+ finalizeDailyAggregateElapsedSeconds += breakdown.dailyAggregateElapsedSeconds |
|
| 2980 |
+ finalizeRunUpdateElapsedSeconds += breakdown.runUpdateElapsedSeconds |
|
| 2981 |
+ finalizeOtherElapsedSeconds += breakdown.otherElapsedSeconds |
|
| 2982 |
+ } |
|
| 2983 |
+ |
|
| 2967 | 2984 |
var importBreakdown: ImportTimingBreakdown {
|
| 2968 | 2985 |
ImportTimingBreakdown( |
| 2969 | 2986 |
fetchElapsedSeconds: fetchElapsedSeconds, |
| 2970 | 2987 |
processingElapsedSeconds: processingElapsedSeconds, |
| 2971 | 2988 |
insertElapsedSeconds: insertElapsedSeconds, |
| 2972 |
- finalizeElapsedSeconds: finalizeElapsedSeconds |
|
| 2989 |
+ finalizeElapsedSeconds: finalizeElapsedSeconds, |
|
| 2990 |
+ finalizeEventCountElapsedSeconds: finalizeEventCountElapsedSeconds, |
|
| 2991 |
+ finalizeTypeSummaryElapsedSeconds: finalizeTypeSummaryElapsedSeconds, |
|
| 2992 |
+ finalizeDailyAggregateElapsedSeconds: finalizeDailyAggregateElapsedSeconds, |
|
| 2993 |
+ finalizeRunUpdateElapsedSeconds: finalizeRunUpdateElapsedSeconds, |
|
| 2994 |
+ finalizeOtherElapsedSeconds: finalizeOtherElapsedSeconds |
|
| 2973 | 2995 |
) |
| 2974 | 2996 |
} |
| 2975 | 2997 |
} |
@@ -9,9 +9,9 @@ protocol HealthArchiveStore {
|
||
| 9 | 9 |
func upsertTypeCaptureState(_ state: HealthArchiveTypeCaptureState, observationID: Int64) async throws |
| 10 | 10 |
func upsertSamples(_ samples: [HKSample], observedAt: Date) async throws -> HealthArchiveWriteSummary |
| 11 | 11 |
func upsertSamples(_ samples: [HKSample], observedAt: Date, observationID: Int64) async throws -> HealthArchiveWriteSummary |
| 12 |
- func markVerification(sampleType: HKSampleType, verifiedAt: Date) async throws |
|
| 13 |
- func markVerification(sampleType: HKSampleType, verifiedAt: Date, observationID: Int64) async throws |
|
| 14 |
- func markUnchangedVerification(sampleType: HKSampleType, verifiedAt: Date, observationID: Int64) async throws |
|
| 12 |
+ func markVerification(sampleType: HKSampleType, verifiedAt: Date) async throws -> HealthArchiveFinalizationBreakdown |
|
| 13 |
+ func markVerification(sampleType: HKSampleType, verifiedAt: Date, observationID: Int64) async throws -> HealthArchiveFinalizationBreakdown |
|
| 14 |
+ func markUnchangedVerification(sampleType: HKSampleType, verifiedAt: Date, observationID: Int64) async throws -> HealthArchiveFinalizationBreakdown |
|
| 15 | 15 |
func recordDisappearance(sampleUUIDHash: String, sampleTypeIdentifier: String, observedMissingAt: Date) async throws |
| 16 | 16 |
func recordDisappearance(sampleUUIDHash: String, sampleTypeIdentifier: String, observedMissingAt: Date, observationID: Int64) async throws |
| 17 | 17 |
func recordDisappearances(sampleUUIDHashes: [String], sampleTypeIdentifier: String, observedMissingAt: Date, observationID: Int64) async throws -> Int |
@@ -32,6 +32,27 @@ struct HealthArchiveWriteSummary: Equatable, Sendable {
|
||
| 32 | 32 |
let unchangedCount: Int |
| 33 | 33 |
} |
| 34 | 34 |
|
| 35 |
+struct HealthArchiveFinalizationBreakdown: Equatable, Sendable {
|
|
| 36 |
+ var eventCountElapsedSeconds: TimeInterval = 0 |
|
| 37 |
+ var typeSummaryElapsedSeconds: TimeInterval = 0 |
|
| 38 |
+ var dailyAggregateElapsedSeconds: TimeInterval = 0 |
|
| 39 |
+ var runUpdateElapsedSeconds: TimeInterval = 0 |
|
| 40 |
+ var totalElapsedSeconds: TimeInterval = 0 |
|
| 41 |
+ |
|
| 42 |
+ static let zero = HealthArchiveFinalizationBreakdown() |
|
| 43 |
+ |
|
| 44 |
+ var accountedElapsedSeconds: TimeInterval {
|
|
| 45 |
+ eventCountElapsedSeconds |
|
| 46 |
+ + typeSummaryElapsedSeconds |
|
| 47 |
+ + dailyAggregateElapsedSeconds |
|
| 48 |
+ + runUpdateElapsedSeconds |
|
| 49 |
+ } |
|
| 50 |
+ |
|
| 51 |
+ var otherElapsedSeconds: TimeInterval {
|
|
| 52 |
+ max(0, totalElapsedSeconds - accountedElapsedSeconds) |
|
| 53 |
+ } |
|
| 54 |
+} |
|
| 55 |
+ |
|
| 35 | 56 |
struct HealthArchiveTypeCaptureState: Equatable, Sendable {
|
| 36 | 57 |
let sampleTypeIdentifier: String |
| 37 | 58 |
let observationID: Int64? |
@@ -182,7 +182,7 @@ actor SQLiteHealthArchiveStore: HealthArchiveStore {
|
||
| 182 | 182 |
} |
| 183 | 183 |
} |
| 184 | 184 |
|
| 185 |
- func markVerification(sampleType: HKSampleType, verifiedAt: Date) async throws {
|
|
| 185 |
+ func markVerification(sampleType: HKSampleType, verifiedAt: Date) async throws -> HealthArchiveFinalizationBreakdown {
|
|
| 186 | 186 |
let db = try openDatabase() |
| 187 | 187 |
defer { sqlite3_close(db) }
|
| 188 | 188 |
try prepareSchemaIfNeeded(db) |
@@ -194,41 +194,44 @@ actor SQLiteHealthArchiveStore: HealthArchiveStore {
|
||
| 194 | 194 |
status: "completed", |
| 195 | 195 |
db: db |
| 196 | 196 |
) |
| 197 |
- try markVerification(sampleType: sampleType, verifiedAt: verifiedAt, observationID: observationID, db: db) |
|
| 197 |
+ let breakdown = try markVerification(sampleType: sampleType, verifiedAt: verifiedAt, observationID: observationID, db: db) |
|
| 198 | 198 |
try execute("COMMIT", db: db)
|
| 199 |
+ return breakdown |
|
| 199 | 200 |
} catch {
|
| 200 | 201 |
try? execute("ROLLBACK", db: db)
|
| 201 | 202 |
throw error |
| 202 | 203 |
} |
| 203 | 204 |
} |
| 204 | 205 |
|
| 205 |
- func markVerification(sampleType: HKSampleType, verifiedAt: Date, observationID: Int64) async throws {
|
|
| 206 |
+ func markVerification(sampleType: HKSampleType, verifiedAt: Date, observationID: Int64) async throws -> HealthArchiveFinalizationBreakdown {
|
|
| 206 | 207 |
let db = try openDatabase() |
| 207 | 208 |
defer { sqlite3_close(db) }
|
| 208 | 209 |
try prepareSchemaIfNeeded(db) |
| 209 | 210 |
try execute("BEGIN IMMEDIATE TRANSACTION", db: db)
|
| 210 | 211 |
do {
|
| 211 |
- try markVerification(sampleType: sampleType, verifiedAt: verifiedAt, observationID: observationID, db: db) |
|
| 212 |
+ let breakdown = try markVerification(sampleType: sampleType, verifiedAt: verifiedAt, observationID: observationID, db: db) |
|
| 212 | 213 |
try execute("COMMIT", db: db)
|
| 214 |
+ return breakdown |
|
| 213 | 215 |
} catch {
|
| 214 | 216 |
try? execute("ROLLBACK", db: db)
|
| 215 | 217 |
throw error |
| 216 | 218 |
} |
| 217 | 219 |
} |
| 218 | 220 |
|
| 219 |
- func markUnchangedVerification(sampleType: HKSampleType, verifiedAt: Date, observationID: Int64) async throws {
|
|
| 221 |
+ func markUnchangedVerification(sampleType: HKSampleType, verifiedAt: Date, observationID: Int64) async throws -> HealthArchiveFinalizationBreakdown {
|
|
| 220 | 222 |
let db = try openDatabase() |
| 221 | 223 |
defer { sqlite3_close(db) }
|
| 222 | 224 |
try prepareSchemaIfNeeded(db) |
| 223 | 225 |
try execute("BEGIN IMMEDIATE TRANSACTION", db: db)
|
| 224 | 226 |
do {
|
| 225 |
- try markUnchangedVerification( |
|
| 227 |
+ let breakdown = try markUnchangedVerification( |
|
| 226 | 228 |
sampleType: sampleType, |
| 227 | 229 |
verifiedAt: verifiedAt, |
| 228 | 230 |
observationID: observationID, |
| 229 | 231 |
db: db |
| 230 | 232 |
) |
| 231 | 233 |
try execute("COMMIT", db: db)
|
| 234 |
+ return breakdown |
|
| 232 | 235 |
} catch {
|
| 233 | 236 |
try? execute("ROLLBACK", db: db)
|
| 234 | 237 |
throw error |
@@ -1999,7 +2002,9 @@ actor SQLiteHealthArchiveStore: HealthArchiveStore {
|
||
| 1999 | 2002 |
verifiedAt: Date, |
| 2000 | 2003 |
observationID: Int64, |
| 2001 | 2004 |
db: OpaquePointer? |
| 2002 |
- ) throws {
|
|
| 2005 |
+ ) throws -> HealthArchiveFinalizationBreakdown {
|
|
| 2006 |
+ let startedAt = Date() |
|
| 2007 |
+ var breakdown = HealthArchiveFinalizationBreakdown.zero |
|
| 2003 | 2008 |
let statementCache = SQLiteStatementCache(db: db) |
| 2004 | 2009 |
defer { statementCache.finalizeAll() }
|
| 2005 | 2010 |
let lookupCache = SQLiteWriteLookupCache() |
@@ -2009,6 +2014,7 @@ actor SQLiteHealthArchiveStore: HealthArchiveStore {
|
||
| 2009 | 2014 |
statementCache: statementCache, |
| 2010 | 2015 |
lookupCache: lookupCache |
| 2011 | 2016 |
) |
| 2017 |
+ let eventCountStartedAt = Date() |
|
| 2012 | 2018 |
let counts = try eventCounts(observationID: observationID, sampleTypeID: sampleTypeID, db: db) |
| 2013 | 2019 |
let previousSummary = try previousTypeSummary( |
| 2014 | 2020 |
sampleTypeID: sampleTypeID, |
@@ -2016,10 +2022,12 @@ actor SQLiteHealthArchiveStore: HealthArchiveStore {
|
||
| 2016 | 2022 |
db: db, |
| 2017 | 2023 |
statementCache: statementCache |
| 2018 | 2024 |
) |
| 2025 |
+ breakdown.eventCountElapsedSeconds += Date().timeIntervalSince(eventCountStartedAt) |
|
| 2019 | 2026 |
if counts.appeared == 0, |
| 2020 | 2027 |
counts.disappeared == 0, |
| 2021 | 2028 |
counts.representationChanged == 0, |
| 2022 | 2029 |
let previousSummary {
|
| 2030 |
+ let runStartedAt = Date() |
|
| 2023 | 2031 |
try insertObservationTypeRun( |
| 2024 | 2032 |
observationID: observationID, |
| 2025 | 2033 |
sampleTypeID: sampleTypeID, |
@@ -2031,6 +2039,8 @@ actor SQLiteHealthArchiveStore: HealthArchiveStore {
|
||
| 2031 | 2039 |
db: db, |
| 2032 | 2040 |
statementCache: statementCache |
| 2033 | 2041 |
) |
| 2042 |
+ breakdown.runUpdateElapsedSeconds += Date().timeIntervalSince(runStartedAt) |
|
| 2043 |
+ let summaryStartedAt = Date() |
|
| 2034 | 2044 |
try upsertTypeSummary( |
| 2035 | 2045 |
observationID: observationID, |
| 2036 | 2046 |
sampleTypeID: sampleTypeID, |
@@ -2038,15 +2048,20 @@ actor SQLiteHealthArchiveStore: HealthArchiveStore {
|
||
| 2038 | 2048 |
aggregate: previousSummary.aggregate, |
| 2039 | 2049 |
db: db |
| 2040 | 2050 |
) |
| 2051 |
+ breakdown.typeSummaryElapsedSeconds += Date().timeIntervalSince(summaryStartedAt) |
|
| 2052 |
+ let dailyStartedAt = Date() |
|
| 2041 | 2053 |
try copyDailyAggregates( |
| 2042 | 2054 |
fromObservationID: previousSummary.observationID, |
| 2043 | 2055 |
toObservationID: observationID, |
| 2044 | 2056 |
sampleTypeID: sampleTypeID, |
| 2045 | 2057 |
db: db |
| 2046 | 2058 |
) |
| 2047 |
- return |
|
| 2059 |
+ breakdown.dailyAggregateElapsedSeconds += Date().timeIntervalSince(dailyStartedAt) |
|
| 2060 |
+ breakdown.totalElapsedSeconds = Date().timeIntervalSince(startedAt) |
|
| 2061 |
+ return breakdown |
|
| 2048 | 2062 |
} |
| 2049 | 2063 |
|
| 2064 |
+ let summaryStartedAt = Date() |
|
| 2050 | 2065 |
let aggregate = try incrementalVisibleAggregate( |
| 2051 | 2066 |
previous: previousSummary?.aggregate, |
| 2052 | 2067 |
observationID: observationID, |
@@ -2054,6 +2069,8 @@ actor SQLiteHealthArchiveStore: HealthArchiveStore {
|
||
| 2054 | 2069 |
db: db |
| 2055 | 2070 |
) ?? visibleAggregate(sampleTypeID: sampleTypeID, db: db) |
| 2056 | 2071 |
let visibleCount = aggregate.visibleRecordCount |
| 2072 |
+ breakdown.typeSummaryElapsedSeconds += Date().timeIntervalSince(summaryStartedAt) |
|
| 2073 |
+ let runStartedAt = Date() |
|
| 2057 | 2074 |
try insertObservationTypeRun( |
| 2058 | 2075 |
observationID: observationID, |
| 2059 | 2076 |
sampleTypeID: sampleTypeID, |
@@ -2065,6 +2082,8 @@ actor SQLiteHealthArchiveStore: HealthArchiveStore {
|
||
| 2065 | 2082 |
db: db, |
| 2066 | 2083 |
statementCache: statementCache |
| 2067 | 2084 |
) |
| 2085 |
+ breakdown.runUpdateElapsedSeconds += Date().timeIntervalSince(runStartedAt) |
|
| 2086 |
+ let summaryUpsertStartedAt = Date() |
|
| 2068 | 2087 |
try upsertTypeSummary( |
| 2069 | 2088 |
observationID: observationID, |
| 2070 | 2089 |
sampleTypeID: sampleTypeID, |
@@ -2072,6 +2091,8 @@ actor SQLiteHealthArchiveStore: HealthArchiveStore {
|
||
| 2072 | 2091 |
aggregate: aggregate, |
| 2073 | 2092 |
db: db |
| 2074 | 2093 |
) |
| 2094 |
+ breakdown.typeSummaryElapsedSeconds += Date().timeIntervalSince(summaryUpsertStartedAt) |
|
| 2095 |
+ let dailyStartedAt = Date() |
|
| 2075 | 2096 |
if let previousSummary, |
| 2076 | 2097 |
try replaceChangedDailyAggregates( |
| 2077 | 2098 |
fromObservationID: previousSummary.observationID, |
@@ -2080,7 +2101,9 @@ actor SQLiteHealthArchiveStore: HealthArchiveStore {
|
||
| 2080 | 2101 |
observedAt: verifiedAt, |
| 2081 | 2102 |
db: db |
| 2082 | 2103 |
) {
|
| 2083 |
- return |
|
| 2104 |
+ breakdown.dailyAggregateElapsedSeconds += Date().timeIntervalSince(dailyStartedAt) |
|
| 2105 |
+ breakdown.totalElapsedSeconds = Date().timeIntervalSince(startedAt) |
|
| 2106 |
+ return breakdown |
|
| 2084 | 2107 |
} |
| 2085 | 2108 |
|
| 2086 | 2109 |
try rebuildDailyAggregates( |
@@ -2089,6 +2112,9 @@ actor SQLiteHealthArchiveStore: HealthArchiveStore {
|
||
| 2089 | 2112 |
observedAt: verifiedAt, |
| 2090 | 2113 |
db: db |
| 2091 | 2114 |
) |
| 2115 |
+ breakdown.dailyAggregateElapsedSeconds += Date().timeIntervalSince(dailyStartedAt) |
|
| 2116 |
+ breakdown.totalElapsedSeconds = Date().timeIntervalSince(startedAt) |
|
| 2117 |
+ return breakdown |
|
| 2092 | 2118 |
} |
| 2093 | 2119 |
|
| 2094 | 2120 |
private func markUnchangedVerification( |
@@ -2096,7 +2122,9 @@ actor SQLiteHealthArchiveStore: HealthArchiveStore {
|
||
| 2096 | 2122 |
verifiedAt: Date, |
| 2097 | 2123 |
observationID: Int64, |
| 2098 | 2124 |
db: OpaquePointer? |
| 2099 |
- ) throws {
|
|
| 2125 |
+ ) throws -> HealthArchiveFinalizationBreakdown {
|
|
| 2126 |
+ let startedAt = Date() |
|
| 2127 |
+ var breakdown = HealthArchiveFinalizationBreakdown.zero |
|
| 2100 | 2128 |
let statementCache = SQLiteStatementCache(db: db) |
| 2101 | 2129 |
defer { statementCache.finalizeAll() }
|
| 2102 | 2130 |
let lookupCache = SQLiteWriteLookupCache() |
@@ -2106,21 +2134,24 @@ actor SQLiteHealthArchiveStore: HealthArchiveStore {
|
||
| 2106 | 2134 |
statementCache: statementCache, |
| 2107 | 2135 |
lookupCache: lookupCache |
| 2108 | 2136 |
) |
| 2137 |
+ let lookupStartedAt = Date() |
|
| 2109 | 2138 |
guard let previousSummary = try previousTypeSummary( |
| 2110 | 2139 |
sampleTypeID: sampleTypeID, |
| 2111 | 2140 |
beforeObservationID: observationID, |
| 2112 | 2141 |
db: db, |
| 2113 | 2142 |
statementCache: statementCache |
| 2114 | 2143 |
) else {
|
| 2115 |
- try markVerification( |
|
| 2144 |
+ breakdown.eventCountElapsedSeconds += Date().timeIntervalSince(lookupStartedAt) |
|
| 2145 |
+ return try markVerification( |
|
| 2116 | 2146 |
sampleType: sampleType, |
| 2117 | 2147 |
verifiedAt: verifiedAt, |
| 2118 | 2148 |
observationID: observationID, |
| 2119 | 2149 |
db: db |
| 2120 | 2150 |
) |
| 2121 |
- return |
|
| 2122 | 2151 |
} |
| 2152 |
+ breakdown.eventCountElapsedSeconds += Date().timeIntervalSince(lookupStartedAt) |
|
| 2123 | 2153 |
|
| 2154 |
+ let runStartedAt = Date() |
|
| 2124 | 2155 |
try insertObservationTypeRun( |
| 2125 | 2156 |
observationID: observationID, |
| 2126 | 2157 |
sampleTypeID: sampleTypeID, |
@@ -2132,6 +2163,8 @@ actor SQLiteHealthArchiveStore: HealthArchiveStore {
|
||
| 2132 | 2163 |
db: db, |
| 2133 | 2164 |
statementCache: statementCache |
| 2134 | 2165 |
) |
| 2166 |
+ breakdown.runUpdateElapsedSeconds += Date().timeIntervalSince(runStartedAt) |
|
| 2167 |
+ let summaryStartedAt = Date() |
|
| 2135 | 2168 |
try upsertTypeSummary( |
| 2136 | 2169 |
observationID: observationID, |
| 2137 | 2170 |
sampleTypeID: sampleTypeID, |
@@ -2139,12 +2172,17 @@ actor SQLiteHealthArchiveStore: HealthArchiveStore {
|
||
| 2139 | 2172 |
aggregate: previousSummary.aggregate, |
| 2140 | 2173 |
db: db |
| 2141 | 2174 |
) |
| 2175 |
+ breakdown.typeSummaryElapsedSeconds += Date().timeIntervalSince(summaryStartedAt) |
|
| 2176 |
+ let dailyStartedAt = Date() |
|
| 2142 | 2177 |
try copyDailyAggregates( |
| 2143 | 2178 |
fromObservationID: previousSummary.observationID, |
| 2144 | 2179 |
toObservationID: observationID, |
| 2145 | 2180 |
sampleTypeID: sampleTypeID, |
| 2146 | 2181 |
db: db |
| 2147 | 2182 |
) |
| 2183 |
+ breakdown.dailyAggregateElapsedSeconds += Date().timeIntervalSince(dailyStartedAt) |
|
| 2184 |
+ breakdown.totalElapsedSeconds = Date().timeIntervalSince(startedAt) |
|
| 2185 |
+ return breakdown |
|
| 2148 | 2186 |
} |
| 2149 | 2187 |
|
| 2150 | 2188 |
private func recordDisappearance( |
@@ -5,12 +5,25 @@ struct ImportTimingBreakdown: Sendable, Equatable {
|
||
| 5 | 5 |
var processingElapsedSeconds: TimeInterval = 0 |
| 6 | 6 |
var insertElapsedSeconds: TimeInterval = 0 |
| 7 | 7 |
var finalizeElapsedSeconds: TimeInterval = 0 |
| 8 |
+ var finalizeEventCountElapsedSeconds: TimeInterval = 0 |
|
| 9 |
+ var finalizeTypeSummaryElapsedSeconds: TimeInterval = 0 |
|
| 10 |
+ var finalizeDailyAggregateElapsedSeconds: TimeInterval = 0 |
|
| 11 |
+ var finalizeRunUpdateElapsedSeconds: TimeInterval = 0 |
|
| 12 |
+ var finalizeOtherElapsedSeconds: TimeInterval = 0 |
|
| 8 | 13 |
|
| 9 | 14 |
static let zero = ImportTimingBreakdown() |
| 10 | 15 |
|
| 11 | 16 |
var accountedElapsedSeconds: TimeInterval {
|
| 12 | 17 |
fetchElapsedSeconds + processingElapsedSeconds + insertElapsedSeconds + finalizeElapsedSeconds |
| 13 | 18 |
} |
| 19 |
+ |
|
| 20 |
+ var finalizeAccountedElapsedSeconds: TimeInterval {
|
|
| 21 |
+ finalizeEventCountElapsedSeconds |
|
| 22 |
+ + finalizeTypeSummaryElapsedSeconds |
|
| 23 |
+ + finalizeDailyAggregateElapsedSeconds |
|
| 24 |
+ + finalizeRunUpdateElapsedSeconds |
|
| 25 |
+ + finalizeOtherElapsedSeconds |
|
| 26 |
+ } |
|
| 14 | 27 |
} |
| 15 | 28 |
|
| 16 | 29 |
struct HealthKitAPICallResult: Sendable, Equatable {
|
@@ -150,6 +163,11 @@ final class SnapshotFetchProgress {
|
||
| 150 | 163 |
combined.processingElapsedSeconds += type.timingBreakdown.processingElapsedSeconds |
| 151 | 164 |
combined.insertElapsedSeconds += type.timingBreakdown.insertElapsedSeconds |
| 152 | 165 |
combined.finalizeElapsedSeconds += type.timingBreakdown.finalizeElapsedSeconds |
| 166 |
+ combined.finalizeEventCountElapsedSeconds += type.timingBreakdown.finalizeEventCountElapsedSeconds |
|
| 167 |
+ combined.finalizeTypeSummaryElapsedSeconds += type.timingBreakdown.finalizeTypeSummaryElapsedSeconds |
|
| 168 |
+ combined.finalizeDailyAggregateElapsedSeconds += type.timingBreakdown.finalizeDailyAggregateElapsedSeconds |
|
| 169 |
+ combined.finalizeRunUpdateElapsedSeconds += type.timingBreakdown.finalizeRunUpdateElapsedSeconds |
|
| 170 |
+ combined.finalizeOtherElapsedSeconds += type.timingBreakdown.finalizeOtherElapsedSeconds |
|
| 153 | 171 |
return combined |
| 154 | 172 |
} |
| 155 | 173 |
} |
@@ -394,6 +394,13 @@ struct DashboardView: View {
|
||
| 394 | 394 |
lines.append("SummedProcessingElapsed: \(formatDuration(aggregateTiming.processingElapsedSeconds))")
|
| 395 | 395 |
lines.append("SummedInsertElapsed: \(formatDuration(aggregateTiming.insertElapsedSeconds))")
|
| 396 | 396 |
lines.append("SummedFinalizeElapsed: \(formatDuration(aggregateTiming.finalizeElapsedSeconds))")
|
| 397 |
+ if aggregateTiming.finalizeAccountedElapsedSeconds > 0 {
|
|
| 398 |
+ lines.append("SummedFinalizeEventCountElapsed: \(formatDuration(aggregateTiming.finalizeEventCountElapsedSeconds))")
|
|
| 399 |
+ lines.append("SummedFinalizeTypeSummaryElapsed: \(formatDuration(aggregateTiming.finalizeTypeSummaryElapsedSeconds))")
|
|
| 400 |
+ lines.append("SummedFinalizeDailyAggregateElapsed: \(formatDuration(aggregateTiming.finalizeDailyAggregateElapsedSeconds))")
|
|
| 401 |
+ lines.append("SummedFinalizeRunUpdateElapsed: \(formatDuration(aggregateTiming.finalizeRunUpdateElapsedSeconds))")
|
|
| 402 |
+ lines.append("SummedFinalizeOtherElapsed: \(formatDuration(aggregateTiming.finalizeOtherElapsedSeconds))")
|
|
| 403 |
+ } |
|
| 397 | 404 |
lines.append("SummedResidualElapsed: \(formatDuration(summedMetricResidualElapsed))")
|
| 398 | 405 |
lines.append("CaptureModes: unchangedDelta=\(captureModeCounts["unchangedDelta", default: 0]), delta=\(captureModeCounts["delta", default: 0]), initialImport=\(captureModeCounts["initialImport", default: 0]), unavailable=\(captureModeCounts["unavailable", default: 0])")
|
| 399 | 406 |
lines.append("DeltaEvents: \(summedDeltaEventCount)")
|
@@ -441,6 +448,13 @@ struct DashboardView: View {
|
||
| 441 | 448 |
lines.append(" processingElapsed: \(formatDuration(type.timingBreakdown.processingElapsedSeconds))")
|
| 442 | 449 |
lines.append(" insertElapsed: \(formatDuration(type.timingBreakdown.insertElapsedSeconds))")
|
| 443 | 450 |
lines.append(" finalizeElapsed: \(formatDuration(type.timingBreakdown.finalizeElapsedSeconds))")
|
| 451 |
+ if type.timingBreakdown.finalizeAccountedElapsedSeconds > 0 {
|
|
| 452 |
+ lines.append(" finalizeEventCountElapsed: \(formatDuration(type.timingBreakdown.finalizeEventCountElapsedSeconds))")
|
|
| 453 |
+ lines.append(" finalizeTypeSummaryElapsed: \(formatDuration(type.timingBreakdown.finalizeTypeSummaryElapsedSeconds))")
|
|
| 454 |
+ lines.append(" finalizeDailyAggregateElapsed: \(formatDuration(type.timingBreakdown.finalizeDailyAggregateElapsedSeconds))")
|
|
| 455 |
+ lines.append(" finalizeRunUpdateElapsed: \(formatDuration(type.timingBreakdown.finalizeRunUpdateElapsedSeconds))")
|
|
| 456 |
+ lines.append(" finalizeOtherElapsed: \(formatDuration(type.timingBreakdown.finalizeOtherElapsedSeconds))")
|
|
| 457 |
+ } |
|
| 444 | 458 |
lines.append(" residualElapsed: \(formatDuration(timingResidual(totalElapsed: type.totalElapsedSeconds, breakdown: type.timingBreakdown)))")
|
| 445 | 459 |
if type.blockElapsedSeconds > 0 {
|
| 446 | 460 |
lines.append(" fetchProgressElapsed: \(formatDuration(type.blockElapsedSeconds))")
|