- SDKMetrics singleton for the measurement - download, validate and scan blocks supported - Sample app refactored to use SDKMetrics, connected to appropriate notifications and labels - enhancement metric added - total sync time metric added - sample app extended to show summary time and operations summaries - unit tests for the SDKMetrics - doc for the SDKMetrics and our approach for the performance testing in general - changelog update
This commit is contained in:
Lukas Korba
GitHub
parent
be3ff4299d
commit
3c3b97ca42
|
|
@ -1,3 +1,8 @@
|
|||
# Unreleased
|
||||
- [#663] Foundations for the benchmarking/performance testing in the SDK.
|
||||
This change presents 2 building blocks for the future automated tests, consisting
|
||||
of a new SDKMetrics interface to control flow of the data in the SDK and
|
||||
new performance (unit) test measuring synchronization of 100 mainnet blocks.
|
||||
# 0.17.4-beta
|
||||
- [#665] Fix testShieldFunds() `get_transparent_balance` error
|
||||
updates `libzcashlc` to `0.1.1` to fix an error where getting a
|
||||
|
|
|
|||
|
|
@ -140,8 +140,8 @@
|
|||
"kind" : "remoteSourceControl",
|
||||
"location" : "https://github.com/zcash-hackworks/zcash-light-client-ffi",
|
||||
"state" : {
|
||||
"revision" : "fad9802b907822d5a1877584c91f3786824521b7",
|
||||
"version" : "0.1.0"
|
||||
"revision" : "b6013b8b313523b2c72ce62dbdc17f6ffad3a500",
|
||||
"version" : "0.1.1"
|
||||
}
|
||||
}
|
||||
],
|
||||
|
|
|
|||
|
|
@ -959,16 +959,16 @@
|
|||
</constraints>
|
||||
</view>
|
||||
<stackView opaque="NO" contentMode="scaleToFill" verticalHuggingPriority="246" verticalCompressionResistancePriority="250" ambiguous="YES" alignment="center" spacing="13" translatesAutoresizingMaskIntoConstraints="NO" id="IIl-kO-2M8">
|
||||
<rect key="frame" x="0.0" y="79" width="374" height="102"/>
|
||||
<rect key="frame" x="0.0" y="79" width="374" height="114"/>
|
||||
<subviews>
|
||||
<label opaque="NO" userInteractionEnabled="NO" contentMode="left" horizontalHuggingPriority="252" text="Status:" textAlignment="natural" lineBreakMode="tailTruncation" baselineAdjustment="alignBaselines" adjustsFontSizeToFit="NO" translatesAutoresizingMaskIntoConstraints="NO" id="3t3-Tr-UlI">
|
||||
<rect key="frame" x="0.0" y="32" width="95.666666666666671" height="38.333333333333343"/>
|
||||
<rect key="frame" x="0.0" y="38" width="95.666666666666671" height="38.333333333333343"/>
|
||||
<fontDescription key="fontDescription" type="system" pointSize="32"/>
|
||||
<nil key="textColor"/>
|
||||
<nil key="highlightedColor"/>
|
||||
</label>
|
||||
<label opaque="NO" userInteractionEnabled="NO" contentMode="left" horizontalHuggingPriority="251" verticalHuggingPriority="251" text="Label" textAlignment="natural" lineBreakMode="tailTruncation" baselineAdjustment="alignBaselines" adjustsFontSizeToFit="NO" translatesAutoresizingMaskIntoConstraints="NO" id="Jj9-7r-s2Y">
|
||||
<rect key="frame" x="108.66666666666666" y="37.333333333333343" width="265.33333333333337" height="27.666666666666671"/>
|
||||
<rect key="frame" x="108.66666666666666" y="43.333333333333343" width="265.33333333333337" height="27.666666666666671"/>
|
||||
<fontDescription key="fontDescription" type="italicSystem" pointSize="23"/>
|
||||
<color key="textColor" systemColor="scrollViewTexturedBackgroundColor"/>
|
||||
<nil key="highlightedColor"/>
|
||||
|
|
@ -979,22 +979,22 @@
|
|||
</constraints>
|
||||
</stackView>
|
||||
<label opaque="NO" userInteractionEnabled="NO" contentMode="left" horizontalHuggingPriority="251" verticalHuggingPriority="251" ambiguous="YES" text="Progress" textAlignment="center" lineBreakMode="tailTruncation" baselineAdjustment="alignBaselines" adjustsFontSizeToFit="NO" translatesAutoresizingMaskIntoConstraints="NO" id="JPx-ol-2nc">
|
||||
<rect key="frame" x="0.0" y="205" width="366" height="43"/>
|
||||
<rect key="frame" x="0.0" y="217" width="366" height="43"/>
|
||||
<fontDescription key="fontDescription" type="system" pointSize="36"/>
|
||||
<nil key="textColor"/>
|
||||
<nil key="highlightedColor"/>
|
||||
</label>
|
||||
<progressView opaque="NO" contentMode="scaleToFill" verticalHuggingPriority="750" ambiguous="YES" progressViewStyle="bar" progress="0.5" translatesAutoresizingMaskIntoConstraints="NO" id="oKg-9s-8Ym">
|
||||
<rect key="frame" x="0.0" y="272" width="366" height="2.6666666666666856"/>
|
||||
<rect key="frame" x="0.0" y="284" width="366" height="2.6666666666666856"/>
|
||||
</progressView>
|
||||
<label opaque="NO" userInteractionEnabled="NO" contentMode="left" horizontalHuggingPriority="251" verticalHuggingPriority="251" ambiguous="YES" text="0%" textAlignment="center" lineBreakMode="tailTruncation" baselineAdjustment="alignBaselines" adjustsFontSizeToFit="NO" translatesAutoresizingMaskIntoConstraints="NO" id="kXE-5z-HN2">
|
||||
<rect key="frame" x="0.0" y="297.66666666666669" width="374" height="39.666666666666686"/>
|
||||
<rect key="frame" x="0.0" y="309.66666666666669" width="374" height="39.666666666666686"/>
|
||||
<fontDescription key="fontDescription" type="system" pointSize="33"/>
|
||||
<nil key="textColor"/>
|
||||
<nil key="highlightedColor"/>
|
||||
</label>
|
||||
<button opaque="NO" contentMode="scaleToFill" ambiguous="YES" contentHorizontalAlignment="center" contentVerticalAlignment="center" buttonType="system" lineBreakMode="middleTruncation" translatesAutoresizingMaskIntoConstraints="NO" id="G5M-gm-1ux">
|
||||
<rect key="frame" x="0.0" y="361.33333333333331" width="374" height="45"/>
|
||||
<rect key="frame" x="0.0" y="373.33333333333331" width="374" height="45"/>
|
||||
<fontDescription key="fontDescription" type="system" pointSize="27"/>
|
||||
<state key="normal" title="Start"/>
|
||||
<connections>
|
||||
|
|
@ -1002,14 +1002,14 @@
|
|||
</connections>
|
||||
</button>
|
||||
<label opaque="NO" userInteractionEnabled="NO" contentMode="left" horizontalHuggingPriority="251" verticalHuggingPriority="251" ambiguous="YES" text="Label" textAlignment="natural" lineBreakMode="tailTruncation" numberOfLines="0" baselineAdjustment="alignBaselines" adjustsFontSizeToFit="NO" translatesAutoresizingMaskIntoConstraints="NO" id="XK2-GA-Ufv">
|
||||
<rect key="frame" x="0.0" y="430.33333333333337" width="374" height="20.333333333333314"/>
|
||||
<fontDescription key="fontDescription" type="system" pointSize="17"/>
|
||||
<rect key="frame" x="0.0" y="442.33333333333337" width="374" height="14.333333333333314"/>
|
||||
<fontDescription key="fontDescription" type="system" pointSize="12"/>
|
||||
<nil key="textColor"/>
|
||||
<nil key="highlightedColor"/>
|
||||
</label>
|
||||
<label opaque="NO" userInteractionEnabled="NO" contentMode="left" horizontalHuggingPriority="251" verticalHuggingPriority="251" ambiguous="YES" text="Label" textAlignment="natural" lineBreakMode="tailTruncation" numberOfLines="0" baselineAdjustment="alignBaselines" adjustsFontSizeToFit="NO" translatesAutoresizingMaskIntoConstraints="NO" id="ROk-70-c41">
|
||||
<rect key="frame" x="0.0" y="474.66666666666663" width="374" height="20.333333333333314"/>
|
||||
<fontDescription key="fontDescription" type="system" pointSize="17"/>
|
||||
<rect key="frame" x="0.0" y="480.66666666666663" width="374" height="14.333333333333314"/>
|
||||
<fontDescription key="fontDescription" type="system" pointSize="12"/>
|
||||
<nil key="textColor"/>
|
||||
<nil key="highlightedColor"/>
|
||||
</label>
|
||||
|
|
|
|||
|
|
@ -19,10 +19,20 @@ class SyncBlocksViewController: UIViewController {
|
|||
@IBOutlet weak var startPause: UIButton!
|
||||
@IBOutlet weak var metricLabel: UILabel!
|
||||
@IBOutlet weak var summaryLabel: UILabel!
|
||||
var lastMetric = PassthroughSubject<SDKMetrics.BlockMetricReport, Never>()
|
||||
|
||||
private var queue = DispatchQueue(label: "metrics.queue", qos: .default)
|
||||
private var accumulatedMetrics: ProcessorMetrics = .initial
|
||||
private var currentMetric: SDKMetrics.Operation?
|
||||
private var currentMetricName: String {
|
||||
guard let currentMetric else { return "" }
|
||||
switch currentMetric {
|
||||
case .downloadBlocks: return "download: "
|
||||
case .validateBlocks: return "validate: "
|
||||
case .scanBlocks: return "scan: "
|
||||
case .enhancement: return "enhancement: "
|
||||
case .fetchUTXOs: return "fetchUTXOs: "
|
||||
}
|
||||
}
|
||||
|
||||
let synchronizer = AppDelegate.shared.sharedSynchronizer
|
||||
|
||||
|
|
@ -65,27 +75,47 @@ class SyncBlocksViewController: UIViewController {
|
|||
.store(in: ¬ificationCancellables)
|
||||
}
|
||||
|
||||
self.lastMetric
|
||||
.throttle(for: 5, scheduler: DispatchQueue.main, latest: true)
|
||||
.receive(on: DispatchQueue.main)
|
||||
.sink { report in
|
||||
// handle report
|
||||
self.metricLabel.text = report.debugDescription
|
||||
NotificationCenter.default.publisher(for: .blockProcessorStartedDownloading, object: nil)
|
||||
.sink { [weak self] _ in
|
||||
self?.currentMetric = .downloadBlocks
|
||||
}
|
||||
.store(in: ¬ificationCancellables)
|
||||
|
||||
NotificationCenter.default.publisher(for: SDKMetrics.notificationName)
|
||||
.receive(on: queue)
|
||||
.compactMap { SDKMetrics.blockReportFromNotification($0) }
|
||||
.map { [weak self] report in
|
||||
guard let self = self else { return report }
|
||||
NotificationCenter.default.publisher(for: .blockProcessorStartedValidating, object: nil)
|
||||
.receive(on: DispatchQueue.main)
|
||||
.sink { [weak self] _ in
|
||||
self?.accumulateMetrics()
|
||||
self?.summaryLabel.text = "download: \((self?.accumulatedMetrics.debugDescription ?? "No summary"))"
|
||||
self?.accumulatedMetrics = .initial
|
||||
self?.currentMetric = .validateBlocks
|
||||
}
|
||||
.store(in: ¬ificationCancellables)
|
||||
|
||||
self.accumulatedMetrics = .accummulate(self.accumulatedMetrics, current: report)
|
||||
NotificationCenter.default.publisher(for: .blockProcessorStartedScanning, object: nil)
|
||||
.sink { [weak self] _ in
|
||||
self?.currentMetric = .scanBlocks
|
||||
}
|
||||
.store(in: ¬ificationCancellables)
|
||||
|
||||
return report
|
||||
NotificationCenter.default.publisher(for: .blockProcessorStartedEnhancing, object: nil)
|
||||
.receive(on: DispatchQueue.main)
|
||||
.sink { [weak self] _ in
|
||||
self?.accumulateMetrics()
|
||||
self?.summaryLabel.text = "scan: \((self?.accumulatedMetrics.debugDescription ?? "No summary"))"
|
||||
self?.accumulatedMetrics = .initial
|
||||
self?.currentMetric = .enhancement
|
||||
}
|
||||
.store(in: ¬ificationCancellables)
|
||||
|
||||
NotificationCenter.default.publisher(for: .blockProcessorUpdated, object: nil)
|
||||
.throttle(for: 5, scheduler: DispatchQueue.main, latest: true)
|
||||
.receive(on: DispatchQueue.main)
|
||||
.map { [weak self] _ -> SDKMetrics.BlockMetricReport? in
|
||||
guard let currentMetric = self?.currentMetric else { return nil }
|
||||
return SDKMetrics.shared.popBlock(operation: currentMetric)?.last
|
||||
}
|
||||
.sink { [weak self] report in
|
||||
self?.lastMetric.send(report)
|
||||
self?.metricLabel.text = (self?.currentMetricName ?? "") + report.debugDescription
|
||||
}
|
||||
.store(in: ¬ificationCancellables)
|
||||
|
||||
|
|
@ -93,7 +123,9 @@ class SyncBlocksViewController: UIViewController {
|
|||
.receive(on: DispatchQueue.main)
|
||||
.delay(for: 0.5, scheduler: DispatchQueue.main)
|
||||
.sink { [weak self] _ in
|
||||
self?.summaryLabel.text = self?.accumulatedMetrics.debugDescription ?? "No summary"
|
||||
self?.accumulateMetrics()
|
||||
self?.summaryLabel.text = "enhancement: \((self?.accumulatedMetrics.debugDescription ?? "No summary"))"
|
||||
self?.overallSummary()
|
||||
}
|
||||
.store(in: ¬ificationCancellables)
|
||||
}
|
||||
|
|
@ -117,6 +149,37 @@ class SyncBlocksViewController: UIViewController {
|
|||
return
|
||||
}
|
||||
}
|
||||
|
||||
func accumulateMetrics() {
|
||||
guard let currentMetric else { return }
|
||||
if let reports = SDKMetrics.shared.popBlock(operation: currentMetric) {
|
||||
for report in reports {
|
||||
accumulatedMetrics = .accumulate(accumulatedMetrics, current: report)
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
func overallSummary() {
|
||||
let cumulativeSummary = SDKMetrics.shared.cumulativeSummary()
|
||||
|
||||
let downloadedBlocksReport = cumulativeSummary.downloadedBlocksReport ?? SDKMetrics.ReportSummary.zero
|
||||
let validatedBlocksReport = cumulativeSummary.validatedBlocksReport ?? SDKMetrics.ReportSummary.zero
|
||||
let scannedBlocksReport = cumulativeSummary.scannedBlocksReport ?? SDKMetrics.ReportSummary.zero
|
||||
let enhancementReport = cumulativeSummary.enhancementReport ?? SDKMetrics.ReportSummary.zero
|
||||
let fetchUTXOsReport = cumulativeSummary.fetchUTXOsReport ?? SDKMetrics.ReportSummary.zero
|
||||
let totalSyncReport = cumulativeSummary.totalSyncReport ?? SDKMetrics.ReportSummary.zero
|
||||
|
||||
metricLabel.text =
|
||||
"""
|
||||
Summary:
|
||||
downloadedBlocks: min: \(downloadedBlocksReport.minTime) max: \(downloadedBlocksReport.maxTime) avg: \(downloadedBlocksReport.avgTime)
|
||||
validatedBlocks: min: \(validatedBlocksReport.minTime) max: \(validatedBlocksReport.maxTime) avg: \(validatedBlocksReport.avgTime)
|
||||
scannedBlocks: min: \(scannedBlocksReport.minTime) max: \(scannedBlocksReport.maxTime) avg: \(scannedBlocksReport.avgTime)
|
||||
enhancement: min: \(enhancementReport.minTime) max: \(enhancementReport.maxTime) avg: \(enhancementReport.avgTime)
|
||||
fetchUTXOs: min: \(fetchUTXOsReport.minTime) max: \(fetchUTXOsReport.maxTime) avg: \(fetchUTXOsReport.avgTime)
|
||||
totalSync: min: \(totalSyncReport.minTime) max: \(totalSyncReport.maxTime) avg: \(totalSyncReport.avgTime)
|
||||
"""
|
||||
}
|
||||
|
||||
@IBAction func startStop() {
|
||||
Task { @MainActor in
|
||||
|
|
@ -132,6 +195,7 @@ class SyncBlocksViewController: UIViewController {
|
|||
_ = try synchronizer.prepare(with: DemoAppConfig.seed)
|
||||
}
|
||||
|
||||
SDKMetrics.shared.enableMetrics()
|
||||
try synchronizer.start()
|
||||
updateUI()
|
||||
} catch {
|
||||
|
|
@ -140,6 +204,7 @@ class SyncBlocksViewController: UIViewController {
|
|||
}
|
||||
default:
|
||||
synchronizer.stop()
|
||||
SDKMetrics.shared.disableMetrics()
|
||||
updateUI()
|
||||
}
|
||||
|
||||
|
|
@ -223,11 +288,11 @@ struct ProcessorMetrics {
|
|||
var maxHeight: BlockHeight
|
||||
var maxDuration: (TimeInterval, CompactBlockRange)
|
||||
var minDuration: (TimeInterval, CompactBlockRange)
|
||||
var cummulativeDuration: TimeInterval
|
||||
var cumulativeDuration: TimeInterval
|
||||
var measuredCount: Int
|
||||
|
||||
var averageDuration: TimeInterval {
|
||||
measuredCount > 0 ? cummulativeDuration / Double(measuredCount) : 0
|
||||
measuredCount > 0 ? cumulativeDuration / Double(measuredCount) : 0
|
||||
}
|
||||
|
||||
static let initial = Self.init(
|
||||
|
|
@ -235,11 +300,11 @@ struct ProcessorMetrics {
|
|||
maxHeight: .min,
|
||||
maxDuration: (TimeInterval.leastNonzeroMagnitude, 0 ... 1),
|
||||
minDuration: (TimeInterval.greatestFiniteMagnitude, 0 ... 1),
|
||||
cummulativeDuration: 0,
|
||||
cumulativeDuration: 0,
|
||||
measuredCount: 0
|
||||
)
|
||||
|
||||
static func accummulate(_ prev: ProcessorMetrics, current: SDKMetrics.BlockMetricReport) -> Self {
|
||||
static func accumulate(_ prev: ProcessorMetrics, current: SDKMetrics.BlockMetricReport) -> Self {
|
||||
.init(
|
||||
minHeight: min(prev.minHeight, current.startHeight),
|
||||
maxHeight: max(prev.maxHeight, current.progressHeight),
|
||||
|
|
@ -253,7 +318,7 @@ struct ProcessorMetrics {
|
|||
(current.duration, current.progressHeight - current.batchSize ... current.progressHeight),
|
||||
min
|
||||
),
|
||||
cummulativeDuration: prev.cummulativeDuration + current.duration,
|
||||
cumulativeDuration: prev.cumulativeDuration + current.duration,
|
||||
measuredCount: prev.measuredCount + 1
|
||||
)
|
||||
}
|
||||
|
|
@ -274,12 +339,13 @@ extension ProcessorMetrics: CustomDebugStringConvertible {
|
|||
minHeight: \(self.minHeight)
|
||||
maxHeight: \(self.maxHeight)
|
||||
|
||||
avg scan time: \(self.averageDuration)
|
||||
slowest scanned range:
|
||||
avg time: \(self.averageDuration)
|
||||
overall time: \(self.cumulativeDuration)
|
||||
slowest range:
|
||||
range: \(self.maxDuration.1.description)
|
||||
count: \(self.maxDuration.1.count)
|
||||
seconds: \(self.maxDuration.0)
|
||||
Fastest scanned range:
|
||||
Fastest range:
|
||||
range: \(self.minDuration.1.description)
|
||||
count: \(self.minDuration.1.count)
|
||||
seconds: \(self.minDuration.0)
|
||||
|
|
@ -296,7 +362,7 @@ extension CompactBlockRange {
|
|||
extension SDKMetrics.BlockMetricReport: CustomDebugStringConvertible {
|
||||
public var debugDescription: String {
|
||||
"""
|
||||
BlockMetric: Scan
|
||||
BlockMetric:
|
||||
startHeight: \(self.progressHeight - self.batchSize)
|
||||
endHeight: \(self.progressHeight)
|
||||
batchSize: \(self.batchSize)
|
||||
|
|
|
|||
|
|
@ -16,7 +16,7 @@ let package = Package(
|
|||
dependencies: [
|
||||
.package(url: "https://github.com/grpc/grpc-swift.git", from: "1.8.0"),
|
||||
.package(url: "https://github.com/stephencelis/SQLite.swift.git", from: "0.14.1"),
|
||||
.package(name:"libzcashlc", url: "https://github.com/zcash-hackworks/zcash-light-client-ffi", from: "0.1.1")
|
||||
.package(name:"libzcashlc", url: "https://github.com/zcash-hackworks/zcash-light-client-ffi", from: "0.1.1"),
|
||||
],
|
||||
targets: [
|
||||
.target(
|
||||
|
|
@ -60,6 +60,10 @@ let package = Package(
|
|||
.testTarget(
|
||||
name: "DarksideTests",
|
||||
dependencies: ["ZcashLightClientKit", "TestUtils"]
|
||||
),
|
||||
.testTarget(
|
||||
name: "PerformanceTests",
|
||||
dependencies: ["ZcashLightClientKit", "TestUtils"]
|
||||
)
|
||||
]
|
||||
)
|
||||
|
|
|
|||
|
|
@ -22,6 +22,7 @@ extension CompactBlockProcessor {
|
|||
var targetHeightInternal: BlockHeight?
|
||||
|
||||
do {
|
||||
var startTime = Date()
|
||||
targetHeightInternal = targetHeight
|
||||
if targetHeight == nil {
|
||||
targetHeightInternal = try await service.latestBlockHeightAsync()
|
||||
|
|
@ -38,22 +39,53 @@ extension CompactBlockProcessor {
|
|||
endHeight: latestHeight
|
||||
)
|
||||
|
||||
var counter = 0
|
||||
var lastDownloadedBlockHeight = -1
|
||||
|
||||
for try await zcashCompactBlock in stream {
|
||||
try Task.checkCancellation()
|
||||
buffer.append(zcashCompactBlock)
|
||||
if buffer.count >= blockBufferSize {
|
||||
try await storage.write(blocks: buffer)
|
||||
await blocksBufferWritten(buffer)
|
||||
buffer.removeAll(keepingCapacity: true)
|
||||
}
|
||||
counter += 1
|
||||
lastDownloadedBlockHeight = zcashCompactBlock.height
|
||||
|
||||
let progress = BlockProgress(
|
||||
startHeight: startHeight,
|
||||
targetHeight: latestHeight,
|
||||
progressHeight: zcashCompactBlock.height
|
||||
progressHeight: lastDownloadedBlockHeight
|
||||
)
|
||||
notifyProgress(.download(progress))
|
||||
|
||||
if buffer.count >= blockBufferSize {
|
||||
let finishTime = Date()
|
||||
try await storage.write(blocks: buffer)
|
||||
await blocksBufferWritten(buffer)
|
||||
buffer.removeAll(keepingCapacity: true)
|
||||
|
||||
SDKMetrics.shared.pushProgressReport(
|
||||
progress: progress,
|
||||
start: startTime,
|
||||
end: finishTime,
|
||||
batchSize: Int(blockBufferSize),
|
||||
operation: .downloadBlocks
|
||||
)
|
||||
counter = 0
|
||||
startTime = finishTime
|
||||
}
|
||||
}
|
||||
if counter > 0 {
|
||||
SDKMetrics.shared.pushProgressReport(
|
||||
progress: BlockProgress(
|
||||
startHeight: startHeight,
|
||||
targetHeight: latestHeight,
|
||||
progressHeight: lastDownloadedBlockHeight
|
||||
),
|
||||
start: startTime,
|
||||
end: Date(),
|
||||
batchSize: Int(blockBufferSize),
|
||||
operation: .downloadBlocks
|
||||
)
|
||||
}
|
||||
|
||||
try await storage.write(blocks: buffer)
|
||||
await blocksBufferWritten(buffer)
|
||||
buffer.removeAll(keepingCapacity: true)
|
||||
|
|
|
|||
|
|
@ -64,6 +64,7 @@ extension CompactBlockProcessor {
|
|||
|
||||
// fetch transactions
|
||||
do {
|
||||
let startTime = Date()
|
||||
guard let transactions = try transactionRepository.findTransactions(in: blockRange, limit: Int.max), !transactions.isEmpty else {
|
||||
await internalSyncProgress.set(range.upperBound, .latestEnhancedHeight)
|
||||
LoggerProxy.debug("no transactions detected on range: \(blockRange.printRange)")
|
||||
|
|
@ -100,6 +101,18 @@ extension CompactBlockProcessor {
|
|||
}
|
||||
}
|
||||
}
|
||||
|
||||
SDKMetrics.shared.pushProgressReport(
|
||||
progress: BlockProgress(
|
||||
startHeight: range.lowerBound,
|
||||
targetHeight: range.upperBound,
|
||||
progressHeight: range.upperBound
|
||||
),
|
||||
start: startTime,
|
||||
end: Date(),
|
||||
batchSize: range.count,
|
||||
operation: .enhancement
|
||||
)
|
||||
} catch {
|
||||
LoggerProxy.error("error enhancing transactions! \(error)")
|
||||
throw error
|
||||
|
|
|
|||
|
|
@ -651,7 +651,7 @@ public actor CompactBlockProcessor {
|
|||
|
||||
try await handleSaplingParametersIfNeeded()
|
||||
try await removeCacheDB()
|
||||
|
||||
|
||||
if !Task.isCancelled {
|
||||
await processBatchFinished(height: anyActionExecuted ? ranges.latestBlockHeight : nil)
|
||||
}
|
||||
|
|
|
|||
|
|
@ -26,19 +26,19 @@ extension CompactBlockProcessor {
|
|||
throw error
|
||||
}
|
||||
let scanFinishTime = Date()
|
||||
NotificationSender.default.post(notification:
|
||||
SDKMetrics.progressReportNotification(
|
||||
progress: BlockProgress(
|
||||
startHeight: range.lowerBound,
|
||||
targetHeight: range.upperBound,
|
||||
progressHeight: range.upperBound
|
||||
),
|
||||
start: scanStartTime,
|
||||
end: scanFinishTime,
|
||||
batchSize: Int(batchSize),
|
||||
task: .scanBlocks
|
||||
)
|
||||
|
||||
SDKMetrics.shared.pushProgressReport(
|
||||
progress: BlockProgress(
|
||||
startHeight: range.lowerBound,
|
||||
targetHeight: range.upperBound,
|
||||
progressHeight: range.upperBound
|
||||
),
|
||||
start: scanStartTime,
|
||||
end: scanFinishTime,
|
||||
batchSize: Int(batchSize),
|
||||
operation: .scanBlocks
|
||||
)
|
||||
|
||||
let seconds = scanFinishTime.timeIntervalSinceReferenceDate - scanStartTime.timeIntervalSinceReferenceDate
|
||||
LoggerProxy.debug("Scanned \(range.count) blocks in \(seconds) seconds")
|
||||
} else {
|
||||
|
|
@ -71,14 +71,13 @@ extension CompactBlockProcessor {
|
|||
if scannedNewBlocks {
|
||||
let progress = BlockProgress(startHeight: scanStartHeight, targetHeight: targetScanHeight, progressHeight: lastScannedHeight)
|
||||
notifyProgress(.scan(progress))
|
||||
NotificationSender.default.post(notification:
|
||||
SDKMetrics.progressReportNotification(
|
||||
progress: progress,
|
||||
start: scanStartTime,
|
||||
end: scanFinishTime,
|
||||
batchSize: Int(batchSize),
|
||||
task: .scanBlocks
|
||||
)
|
||||
|
||||
SDKMetrics.shared.pushProgressReport(
|
||||
progress: progress,
|
||||
start: scanStartTime,
|
||||
end: scanFinishTime,
|
||||
batchSize: Int(batchSize),
|
||||
operation: .scanBlocks
|
||||
)
|
||||
|
||||
let heightCount = lastScannedHeight - previousScannedHeight
|
||||
|
|
@ -128,84 +127,3 @@ extension CompactBlockProcessor {
|
|||
}
|
||||
}
|
||||
}
|
||||
|
||||
public enum SDKMetrics {
|
||||
public struct BlockMetricReport {
|
||||
public var startHeight: BlockHeight
|
||||
public var progressHeight: BlockHeight
|
||||
public var targetHeight: BlockHeight
|
||||
public var batchSize: Int
|
||||
public var duration: TimeInterval
|
||||
public var task: TaskReported
|
||||
}
|
||||
|
||||
public enum TaskReported: String {
|
||||
case scanBlocks
|
||||
}
|
||||
|
||||
public static let startBlockHeightKey = "SDKMetrics.startBlockHeightKey"
|
||||
public static let targetBlockHeightKey = "SDKMetrics.targetBlockHeightKey"
|
||||
public static let progressHeightKey = "SDKMetrics.progressHeight"
|
||||
public static let batchSizeKey = "SDKMetrics.batchSize"
|
||||
public static let startDateKey = "SDKMetrics.startDateKey"
|
||||
public static let endDateKey = "SDKMetrics.endDateKey"
|
||||
public static let taskReportedKey = "SDKMetrics.taskReported"
|
||||
public static let notificationName = Notification.Name("SDKMetrics.Notification")
|
||||
|
||||
|
||||
public static func blockReportFromNotification(_ notification: Notification) -> BlockMetricReport? {
|
||||
guard
|
||||
notification.name == notificationName,
|
||||
let info = notification.userInfo,
|
||||
let startHeight = info[startBlockHeightKey] as? BlockHeight,
|
||||
let progressHeight = info[progressHeightKey] as? BlockHeight,
|
||||
let targetHeight = info[targetBlockHeightKey] as? BlockHeight,
|
||||
let batchSize = info[batchSizeKey] as? Int,
|
||||
let task = info[taskReportedKey] as? TaskReported,
|
||||
let startDate = info[startDateKey] as? Date,
|
||||
let endDate = info[endDateKey] as? Date
|
||||
|
||||
else {
|
||||
return nil
|
||||
}
|
||||
|
||||
return BlockMetricReport(
|
||||
startHeight: startHeight,
|
||||
progressHeight: progressHeight,
|
||||
targetHeight: targetHeight,
|
||||
batchSize: batchSize,
|
||||
duration: abs(
|
||||
startDate.timeIntervalSinceReferenceDate - endDate.timeIntervalSinceReferenceDate
|
||||
),
|
||||
task: task
|
||||
)
|
||||
}
|
||||
|
||||
static func progressReportNotification(
|
||||
progress: BlockProgress,
|
||||
start: Date,
|
||||
end: Date,
|
||||
batchSize: Int,
|
||||
task: SDKMetrics.TaskReported
|
||||
) -> Notification {
|
||||
var notification = Notification(name: notificationName)
|
||||
notification.userInfo = [
|
||||
startBlockHeightKey: progress.startHeight,
|
||||
targetBlockHeightKey: progress.targetHeight,
|
||||
progressHeightKey: progress.progressHeight,
|
||||
startDateKey: start,
|
||||
endDateKey: end,
|
||||
batchSizeKey: batchSize,
|
||||
taskReportedKey: task
|
||||
]
|
||||
|
||||
return notification
|
||||
}
|
||||
}
|
||||
|
||||
extension String.StringInterpolation {
|
||||
mutating func appendInterpolation(_ value: SDKMetrics.BlockMetricReport) {
|
||||
let literal = "\(value.task) - \(abs(value.startHeight - value.targetHeight)) processed on \(value.duration) seconds"
|
||||
appendLiteral(literal)
|
||||
}
|
||||
}
|
||||
|
|
|
|||
|
|
@ -19,8 +19,18 @@ extension CompactBlockProcessor {
|
|||
|
||||
state = .validating
|
||||
|
||||
let startTime = Date()
|
||||
let result = rustBackend.validateCombinedChain(dbCache: config.cacheDb, dbData: config.dataDb, networkType: config.network.networkType)
|
||||
|
||||
let finishTime = Date()
|
||||
|
||||
SDKMetrics.shared.pushProgressReport(
|
||||
progress: BlockProgress(startHeight: 0, targetHeight: 0, progressHeight: 0),
|
||||
start: startTime,
|
||||
end: finishTime,
|
||||
batchSize: 0,
|
||||
operation: .validateBlocks
|
||||
)
|
||||
|
||||
do {
|
||||
switch result {
|
||||
case 0:
|
||||
|
|
|
|||
|
|
@ -43,6 +43,7 @@ extension CompactBlockProcessor {
|
|||
var refreshed: [UnspentTransactionOutputEntity] = []
|
||||
var skipped: [UnspentTransactionOutputEntity] = []
|
||||
|
||||
let startTime = Date()
|
||||
for utxo in utxos {
|
||||
do {
|
||||
try rustBackend.putUnspentTransparentOutput(
|
||||
|
|
@ -62,6 +63,18 @@ extension CompactBlockProcessor {
|
|||
}
|
||||
}
|
||||
|
||||
SDKMetrics.shared.pushProgressReport(
|
||||
progress: BlockProgress(
|
||||
startHeight: range.lowerBound,
|
||||
targetHeight: range.upperBound,
|
||||
progressHeight: range.upperBound
|
||||
),
|
||||
start: startTime,
|
||||
end: Date(),
|
||||
batchSize: range.count,
|
||||
operation: .fetchUTXOs
|
||||
)
|
||||
|
||||
let result = (inserted: refreshed, skipped: skipped)
|
||||
|
||||
NotificationSender.default.post(
|
||||
|
|
|
|||
|
|
@ -0,0 +1,270 @@
|
|||
//
|
||||
// SDKMetrics.swift
|
||||
//
|
||||
//
|
||||
// Created by Lukáš Korba on 13.12.2022.
|
||||
//
|
||||
|
||||
import Foundation
|
||||
|
||||
/// SDK's tool for the measurement of metrics.
|
||||
/// The barebone API of the `SDKMetrics` is all about turning it on/off, pushing new reports in and poping RAW data out.
|
||||
/// The processing of data is either left to the user of `SDKMetrics` or anybody can take an advantage of extension APIs
|
||||
/// providing useful structs and reports.
|
||||
///
|
||||
/// Usage:
|
||||
/// The `SDKMetrics` API has been designed so it has the lowest impact possible on the SDK itself.
|
||||
/// Reporting of the metrics is already in place but ignored until `enableMetrics()` is called. Once turned on, the data is collected
|
||||
/// and cumulated to the in memory structural storage until `disableMetrics()` is called.
|
||||
/// `disableMetrics()` also clears out the in memory storage.
|
||||
///
|
||||
/// To collect data and process it there are 2 ways:
|
||||
///
|
||||
/// 1.
|
||||
/// Get RAW data by calling either `popBlock` or `popAllBlockReports`. The post-processing of data is then delegated to the caller.
|
||||
///
|
||||
/// 2.
|
||||
/// Get cumulated data by using an extension APIs. For the summarized collection, call `cumulativeSummary()`.
|
||||
/// Sometimes, typically when you want to run several iterations, the `cumulateReportsAndStartNewSet()` automatically computes
|
||||
/// cumulativeSummary, stores it and starts to collect a new set. All summaries can be either processed by a caller,
|
||||
/// accessing the collection `cumulativeSummaries` directly or values can be merged into one final summary by calling `summarizedCumulativeReports()`.
|
||||
///
|
||||
/// We encourage you to check`SDKMetricsTests` and other tests in the Test/PerformanceTests/ folder.
|
||||
public class SDKMetrics {
|
||||
public static let shared = SDKMetrics()
|
||||
|
||||
public struct BlockMetricReport: Equatable {
|
||||
public let startHeight: BlockHeight
|
||||
public let progressHeight: BlockHeight
|
||||
public let targetHeight: BlockHeight
|
||||
public let batchSize: Int
|
||||
public let startTime: TimeInterval
|
||||
public let endTime: TimeInterval
|
||||
public var duration: TimeInterval { endTime - startTime }
|
||||
}
|
||||
|
||||
public enum Operation {
|
||||
case downloadBlocks
|
||||
case validateBlocks
|
||||
case scanBlocks
|
||||
case enhancement
|
||||
case fetchUTXOs
|
||||
}
|
||||
|
||||
public struct SyncReport: Equatable {
|
||||
public let startTime: TimeInterval
|
||||
public let endTime: TimeInterval
|
||||
public var duration: TimeInterval { endTime - startTime }
|
||||
}
|
||||
|
||||
public var cumulativeSummaries: [CumulativeSummary] = []
|
||||
public var syncReport: SyncReport?
|
||||
var isEnabled = false
|
||||
var reports: [Operation : [BlockMetricReport]] = [:]
|
||||
|
||||
/// `SDKMetrics` is disabled by default. Any pushed data are simply ignored until `enableMetrics()` is called.
|
||||
public func enableMetrics() {
|
||||
isEnabled = true
|
||||
}
|
||||
|
||||
public func disableMetrics() {
|
||||
isEnabled = false
|
||||
clearAll()
|
||||
}
|
||||
|
||||
/// `SDKMetrics` focuses deeply on sync process and metrics related to it. By default there are reports around
|
||||
/// block operations like download, validate, etc. This method pushes data on a stack for the specific operation.
|
||||
func pushProgressReport(
|
||||
progress: BlockProgress,
|
||||
start: Date,
|
||||
end: Date,
|
||||
batchSize: Int,
|
||||
operation: Operation
|
||||
) {
|
||||
guard isEnabled else { return }
|
||||
|
||||
let blockMetricReport = BlockMetricReport(
|
||||
startHeight: progress.startHeight,
|
||||
progressHeight: progress.progressHeight,
|
||||
targetHeight: progress.targetHeight,
|
||||
batchSize: batchSize,
|
||||
startTime: start.timeIntervalSinceReferenceDate,
|
||||
endTime: end.timeIntervalSinceReferenceDate
|
||||
)
|
||||
|
||||
guard reports[operation] != nil else {
|
||||
reports[operation] = [blockMetricReport]
|
||||
return
|
||||
}
|
||||
|
||||
reports[operation]?.append(blockMetricReport)
|
||||
}
|
||||
|
||||
/// Block synchronisation consists of operations but the whole process is measured also, represented by
|
||||
/// different struct `SyncReport`, missing specifics for the operations like batch size, etc.
|
||||
/// Used for the total syncing time report in the first place.
|
||||
func pushSyncReport(
|
||||
start: Date,
|
||||
end: Date
|
||||
) {
|
||||
guard isEnabled else { return }
|
||||
|
||||
let syncReport = SyncReport(
|
||||
startTime: start.timeIntervalSinceReferenceDate,
|
||||
endTime: end.timeIntervalSinceReferenceDate
|
||||
)
|
||||
|
||||
self.syncReport = syncReport
|
||||
}
|
||||
|
||||
/// A method allowing users of the `SDKMetrics` to pop the RAW data out of the system. For the specific `operation`
|
||||
/// with option to either leave data in the storage or flushing it out and start the next batch of collecting new ones.
|
||||
public func popBlock(operation: Operation, flush: Bool = false) -> [BlockMetricReport]? {
|
||||
defer {
|
||||
if flush { clearReport(operation) }
|
||||
}
|
||||
|
||||
return reports[operation]
|
||||
}
|
||||
|
||||
/// A method allowing users of the `SDKMetrics` to pop the RAW data out of the system. This time for all measured operations
|
||||
/// with option to either leave data in the storage or flushing it out and start the next batch of collecting new ones.
|
||||
public func popAllBlockReports(flush: Bool = false) -> [Operation : [BlockMetricReport]] {
|
||||
defer {
|
||||
if flush { clearAllBlockReports() }
|
||||
}
|
||||
|
||||
return reports
|
||||
}
|
||||
|
||||
func clearReport(_ operation: Operation) {
|
||||
reports.removeValue(forKey: operation)
|
||||
}
|
||||
|
||||
func clearAllBlockReports() {
|
||||
reports.removeAll()
|
||||
cumulativeSummaries.removeAll()
|
||||
}
|
||||
|
||||
func clearAll() {
|
||||
clearAllBlockReports()
|
||||
syncReport = nil
|
||||
}
|
||||
}
|
||||
|
||||
/// This extension provides an API that provides the summary and accumulated reports.
|
||||
/// The RAW data can pulled out and be processed without this extension but we
|
||||
/// wanted to provide a way how to get essential summaries right from the SDK.
|
||||
extension SDKMetrics {
|
||||
public struct CumulativeSummary: Equatable {
|
||||
public let downloadedBlocksReport: ReportSummary?
|
||||
public let validatedBlocksReport: ReportSummary?
|
||||
public let scannedBlocksReport: ReportSummary?
|
||||
public let enhancementReport: ReportSummary?
|
||||
public let fetchUTXOsReport: ReportSummary?
|
||||
public let totalSyncReport: ReportSummary?
|
||||
}
|
||||
|
||||
public struct ReportSummary: Equatable {
|
||||
public let minTime: TimeInterval
|
||||
public let maxTime: TimeInterval
|
||||
public let avgTime: TimeInterval
|
||||
|
||||
public static let zero = Self(minTime: 0, maxTime: 0, avgTime: 0)
|
||||
}
|
||||
|
||||
/// This method takes all the RAW data and computes a `CumulativeSummary` for every `operation`
|
||||
/// independently. A `ReportSummary` is the result per `operation`, providing min, max and avg times.
|
||||
public func cumulativeSummary() -> CumulativeSummary {
|
||||
let downloadReport = summaryFor(reports: reports[.downloadBlocks])
|
||||
let validateReport = summaryFor(reports: reports[.validateBlocks])
|
||||
let scanReport = summaryFor(reports: reports[.scanBlocks])
|
||||
let enhancementReport = summaryFor(reports: reports[.enhancement])
|
||||
let fetchUTXOsReport = summaryFor(reports: reports[.fetchUTXOs])
|
||||
var totalSyncReport: ReportSummary?
|
||||
|
||||
if let duration = SDKMetrics.shared.syncReport?.duration {
|
||||
totalSyncReport = ReportSummary(minTime: duration, maxTime: duration, avgTime: duration)
|
||||
}
|
||||
|
||||
return CumulativeSummary(
|
||||
downloadedBlocksReport: downloadReport,
|
||||
validatedBlocksReport: validateReport,
|
||||
scannedBlocksReport: scanReport,
|
||||
enhancementReport: enhancementReport,
|
||||
fetchUTXOsReport: fetchUTXOsReport,
|
||||
totalSyncReport: totalSyncReport
|
||||
)
|
||||
}
|
||||
|
||||
/// This method computes the `CumulativeSummary` for the RAW data already in the system, stores it
|
||||
/// and leave room for collecting new RAW data. Typical use case is when some code is expected to run several times
|
||||
/// and every run is expected to be a new data collection.
|
||||
/// Usage of this API is then typically followed by calling `summarizedCumulativeReports()` which merges all stored
|
||||
/// cumulative reports into one final report.
|
||||
public func cumulateReportsAndStartNewSet() {
|
||||
cumulativeSummaries.append(cumulativeSummary())
|
||||
reports.removeAll()
|
||||
syncReport = nil
|
||||
}
|
||||
|
||||
/// This method takes all `CumulativeSummary` reports and merge them all together, providing
|
||||
/// final `CumulativeSummary` per `operation`, ensuring right min and max values are in the place
|
||||
/// as well as computes final avg time per `operation`.
|
||||
public func summarizedCumulativeReports() -> CumulativeSummary? {
|
||||
var finalSummary: CumulativeSummary?
|
||||
|
||||
cumulativeSummaries.forEach { summary in
|
||||
finalSummary = CumulativeSummary(
|
||||
downloadedBlocksReport: accumulate(left: finalSummary?.downloadedBlocksReport, right: summary.downloadedBlocksReport),
|
||||
validatedBlocksReport: accumulate(left: finalSummary?.validatedBlocksReport, right: summary.validatedBlocksReport),
|
||||
scannedBlocksReport: accumulate(left: finalSummary?.scannedBlocksReport, right: summary.scannedBlocksReport),
|
||||
enhancementReport: accumulate(left: finalSummary?.enhancementReport, right: summary.enhancementReport),
|
||||
fetchUTXOsReport: accumulate(left: finalSummary?.fetchUTXOsReport, right: summary.fetchUTXOsReport),
|
||||
totalSyncReport: accumulate(left: finalSummary?.totalSyncReport, right: summary.totalSyncReport)
|
||||
)
|
||||
}
|
||||
|
||||
return finalSummary
|
||||
}
|
||||
|
||||
/// Internal helper method that accumulates `ReportSummary` times.
|
||||
func accumulate(left: ReportSummary?, right: ReportSummary?) -> ReportSummary? {
|
||||
guard let left, let right else {
|
||||
if let right {
|
||||
return ReportSummary(
|
||||
minTime: right.minTime,
|
||||
maxTime: right.maxTime,
|
||||
avgTime: right.avgTime
|
||||
)
|
||||
}
|
||||
return nil
|
||||
}
|
||||
|
||||
return ReportSummary(
|
||||
minTime: min(left.minTime, right.minTime),
|
||||
maxTime: max(left.maxTime, right.maxTime),
|
||||
avgTime: (left.avgTime + right.avgTime) * 0.5
|
||||
)
|
||||
}
|
||||
|
||||
/// Internal helper method that computes min, max and avg times for the `BlockMetricReport` collection.
|
||||
func summaryFor(reports: [BlockMetricReport]?) -> ReportSummary? {
|
||||
guard let reports, !reports.isEmpty else { return nil }
|
||||
|
||||
var min: TimeInterval = 99999999.0
|
||||
var max: TimeInterval = 0.0
|
||||
var avg: TimeInterval = 0.0
|
||||
|
||||
reports.forEach { report in
|
||||
let duration = report.duration
|
||||
avg += duration
|
||||
if duration > max { max = duration }
|
||||
if duration < min { min = duration }
|
||||
}
|
||||
// reports.count is guarded to never be a zero
|
||||
avg /= TimeInterval(reports.count)
|
||||
|
||||
return ReportSummary(minTime: min, maxTime: max, avgTime: avg)
|
||||
}
|
||||
}
|
||||
|
|
@ -88,6 +88,19 @@ public extension BlockProgress {
|
|||
static let nullProgress = BlockProgress(startHeight: 0, targetHeight: 0, progressHeight: 0)
|
||||
}
|
||||
|
||||
protocol LatestBlockHeightProvider {
|
||||
func latestBlockHeight(streamer: CompactTxStreamerNIOClient?) throws -> BlockHeight
|
||||
}
|
||||
|
||||
class LiveLatestBlockHeightProvider: LatestBlockHeightProvider {
|
||||
func latestBlockHeight(streamer: CompactTxStreamerNIOClient?) throws -> BlockHeight {
|
||||
guard let height = try? streamer?.getLatestBlock(ChainSpec()).response.wait().compactBlockHeight() else {
|
||||
throw LightWalletServiceError.timeOut
|
||||
}
|
||||
return height
|
||||
}
|
||||
}
|
||||
|
||||
public class LightWalletGRPCService {
|
||||
let channel: Channel
|
||||
let connectionManager: ConnectionStatusManager
|
||||
|
|
@ -95,6 +108,7 @@ public class LightWalletGRPCService {
|
|||
let compactTxStreamerAsync: CompactTxStreamerAsyncClient
|
||||
let singleCallTimeout: TimeLimit
|
||||
let streamingCallTimeout: TimeLimit
|
||||
var latestBlockHeightProvider: LatestBlockHeightProvider = LiveLatestBlockHeightProvider()
|
||||
|
||||
var queue: DispatchQueue
|
||||
|
||||
|
|
@ -197,10 +211,7 @@ extension LightWalletGRPCService: LightWalletService {
|
|||
}
|
||||
|
||||
public func latestBlockHeight() throws -> BlockHeight {
|
||||
guard let height = try? compactTxStreamer.getLatestBlock(ChainSpec()).response.wait().compactBlockHeight() else {
|
||||
throw LightWalletServiceError.timeOut
|
||||
}
|
||||
return height
|
||||
try latestBlockHeightProvider.latestBlockHeight(streamer: compactTxStreamer)
|
||||
}
|
||||
|
||||
public func latestBlockHeightAsync() async throws -> BlockHeight {
|
||||
|
|
|
|||
|
|
@ -119,6 +119,8 @@ public class SDKSynchronizer: Synchronizer {
|
|||
|
||||
private let statusUpdateLock = NSRecursiveLock()
|
||||
|
||||
private var syncStartDate: Date?
|
||||
|
||||
/// Creates an SDKSynchronizer instance
|
||||
/// - Parameter initializer: a wallet Initializer object
|
||||
public convenience init(initializer: Initializer) throws {
|
||||
|
|
@ -147,15 +149,15 @@ public class SDKSynchronizer: Synchronizer {
|
|||
self.transactionRepository = transactionRepository
|
||||
self.utxoRepository = utxoRepository
|
||||
self.blockProcessor = blockProcessor
|
||||
let lastscannedHeight = (try? transactionRepository.lastScannedHeight()) ?? initializer.walletBirthday
|
||||
self.latestScannedHeight = lastscannedHeight
|
||||
let lastScannedHeight = (try? transactionRepository.lastScannedHeight()) ?? initializer.walletBirthday
|
||||
self.latestScannedHeight = lastScannedHeight
|
||||
self.network = initializer.network
|
||||
self.lastStateSubject = CurrentValueSubject(
|
||||
SynchronizerState(
|
||||
shieldedBalance: .zero,
|
||||
transparentBalance: .zero,
|
||||
syncStatus: .unprepared,
|
||||
latestScannedHeight: lastscannedHeight
|
||||
latestScannedHeight: lastScannedHeight
|
||||
)
|
||||
)
|
||||
|
||||
|
|
@ -203,6 +205,7 @@ public class SDKSynchronizer: Synchronizer {
|
|||
]
|
||||
)
|
||||
|
||||
syncStartDate = Date()
|
||||
await blockProcessor.start(retry: retry)
|
||||
}
|
||||
}
|
||||
|
|
@ -460,6 +463,13 @@ public class SDKSynchronizer: Synchronizer {
|
|||
}
|
||||
self.refreshPendingTransactions()
|
||||
self.status = .synced
|
||||
|
||||
if let syncStartDate {
|
||||
SDKMetrics.shared.pushSyncReport(
|
||||
start: syncStartDate,
|
||||
end: Date()
|
||||
)
|
||||
}
|
||||
}
|
||||
|
||||
@objc func processorTransitionUnknown(_ notification: Notification) {
|
||||
|
|
|
|||
|
|
@ -107,11 +107,11 @@ class BlockScanTests: XCTestCase {
|
|||
}
|
||||
|
||||
@objc func observeBenchmark(_ notification: Notification) {
|
||||
guard let report = SDKMetrics.blockReportFromNotification(notification) else {
|
||||
return
|
||||
}
|
||||
let reports = SDKMetrics.shared.popAllBlockReports(flush: true)
|
||||
|
||||
print("observed benchmark: \(report)")
|
||||
reports.forEach {
|
||||
print("observed benchmark: \($0)")
|
||||
}
|
||||
}
|
||||
|
||||
func testScanValidateDownload() async throws {
|
||||
|
|
@ -119,10 +119,12 @@ class BlockScanTests: XCTestCase {
|
|||
|
||||
logger = SampleLogger(logLevel: .debug)
|
||||
|
||||
SDKMetrics.shared.enableMetrics()
|
||||
|
||||
NotificationCenter.default.addObserver(
|
||||
self,
|
||||
selector: #selector(observeBenchmark(_:)),
|
||||
name: SDKMetrics.notificationName,
|
||||
name: .blockProcessorUpdated,
|
||||
object: nil
|
||||
)
|
||||
|
||||
|
|
@ -207,5 +209,7 @@ class BlockScanTests: XCTestCase {
|
|||
XCTFail("Error should have been a timeLimit reached Error - \(error)")
|
||||
}
|
||||
}
|
||||
|
||||
SDKMetrics.shared.disableMetrics()
|
||||
}
|
||||
}
|
||||
|
|
|
|||
|
|
@ -0,0 +1,161 @@
|
|||
//
|
||||
// SDKMetricsTests.swift
|
||||
//
|
||||
//
|
||||
// Created by Lukáš Korba on 19.12.2022.
|
||||
//
|
||||
|
||||
import XCTest
|
||||
@testable import ZcashLightClientKit
|
||||
|
||||
final class SDKMetricsTests: XCTestCase {
|
||||
func testPushDownloadBlocksReport() throws {
|
||||
SDKMetrics.shared.enableMetrics()
|
||||
|
||||
SDKMetrics.shared.pushProgressReport(
|
||||
progress: BlockProgress(
|
||||
startHeight: 1_730_000,
|
||||
targetHeight: 1_730_099,
|
||||
progressHeight: 1_730_050
|
||||
),
|
||||
start: Date(timeIntervalSinceReferenceDate: 0.0),
|
||||
end: Date(timeIntervalSinceReferenceDate: 1.0),
|
||||
batchSize: 10,
|
||||
operation: .downloadBlocks
|
||||
)
|
||||
|
||||
XCTAssertTrue(SDKMetrics.shared.popBlock(operation: .downloadBlocks)?.count == 1)
|
||||
|
||||
if let reports = SDKMetrics.shared.reports[.downloadBlocks], let report = reports.first {
|
||||
XCTAssertEqual(report, SDKMetrics.BlockMetricReport.placeholderA)
|
||||
} else {
|
||||
XCTFail()
|
||||
}
|
||||
|
||||
SDKMetrics.shared.disableMetrics()
|
||||
}
|
||||
|
||||
func testPopDownloadBlocksReport() throws {
|
||||
SDKMetrics.shared.enableMetrics()
|
||||
|
||||
SDKMetrics.shared.reports[.downloadBlocks] = [SDKMetrics.BlockMetricReport.placeholderA]
|
||||
|
||||
if let reports = SDKMetrics.shared.popBlock(operation: .downloadBlocks), let report = reports.first {
|
||||
XCTAssertEqual(report, SDKMetrics.BlockMetricReport.placeholderA)
|
||||
} else {
|
||||
XCTFail()
|
||||
}
|
||||
|
||||
SDKMetrics.shared.disableMetrics()
|
||||
}
|
||||
|
||||
func testCumulativeSummary() throws {
|
||||
SDKMetrics.shared.enableMetrics()
|
||||
|
||||
SDKMetrics.shared.reports[.downloadBlocks] = [SDKMetrics.BlockMetricReport.placeholderA]
|
||||
|
||||
let summary = SDKMetrics.CumulativeSummary(
|
||||
downloadedBlocksReport: SDKMetrics.ReportSummary(minTime: 1.0, maxTime: 1.0, avgTime: 1.0),
|
||||
validatedBlocksReport: nil,
|
||||
scannedBlocksReport: nil,
|
||||
enhancementReport: nil,
|
||||
fetchUTXOsReport: nil,
|
||||
totalSyncReport: nil
|
||||
)
|
||||
|
||||
XCTAssertEqual(summary, SDKMetrics.shared.cumulativeSummary())
|
||||
|
||||
SDKMetrics.shared.disableMetrics()
|
||||
}
|
||||
|
||||
func testCumulateAndStartNewSet() throws {
|
||||
SDKMetrics.shared.enableMetrics()
|
||||
|
||||
SDKMetrics.shared.reports[.downloadBlocks] = [SDKMetrics.BlockMetricReport.placeholderA]
|
||||
SDKMetrics.shared.cumulateReportsAndStartNewSet()
|
||||
|
||||
SDKMetrics.shared.reports[.downloadBlocks] = [SDKMetrics.BlockMetricReport.placeholderA]
|
||||
SDKMetrics.shared.cumulateReportsAndStartNewSet()
|
||||
|
||||
SDKMetrics.shared.reports[.downloadBlocks] = [SDKMetrics.BlockMetricReport.placeholderA]
|
||||
SDKMetrics.shared.cumulateReportsAndStartNewSet()
|
||||
|
||||
XCTAssertTrue(SDKMetrics.shared.cumulativeSummaries.count == 3)
|
||||
|
||||
let summary = SDKMetrics.CumulativeSummary(
|
||||
downloadedBlocksReport: SDKMetrics.ReportSummary(minTime: 1.0, maxTime: 1.0, avgTime: 1.0),
|
||||
validatedBlocksReport: nil,
|
||||
scannedBlocksReport: nil,
|
||||
enhancementReport: nil,
|
||||
fetchUTXOsReport: nil,
|
||||
totalSyncReport: nil
|
||||
)
|
||||
let summaries = [summary, summary, summary]
|
||||
|
||||
XCTAssertEqual(summaries, SDKMetrics.shared.cumulativeSummaries)
|
||||
|
||||
SDKMetrics.shared.disableMetrics()
|
||||
}
|
||||
|
||||
func testCumulativeSummaryMinMaxAvg() throws {
|
||||
SDKMetrics.shared.enableMetrics()
|
||||
|
||||
SDKMetrics.shared.reports[.downloadBlocks] = [SDKMetrics.BlockMetricReport.placeholderA, SDKMetrics.BlockMetricReport.placeholderB]
|
||||
|
||||
let summary = SDKMetrics.CumulativeSummary(
|
||||
downloadedBlocksReport: SDKMetrics.ReportSummary(minTime: 1.0, maxTime: 6.0, avgTime: 3.5),
|
||||
validatedBlocksReport: nil,
|
||||
scannedBlocksReport: nil,
|
||||
enhancementReport: nil,
|
||||
fetchUTXOsReport: nil,
|
||||
totalSyncReport: nil
|
||||
)
|
||||
|
||||
XCTAssertEqual(summary, SDKMetrics.shared.cumulativeSummary())
|
||||
|
||||
SDKMetrics.shared.disableMetrics()
|
||||
}
|
||||
|
||||
func testSummarizedCumulativeReports() throws {
|
||||
SDKMetrics.shared.enableMetrics()
|
||||
|
||||
SDKMetrics.shared.reports[.downloadBlocks] = [SDKMetrics.BlockMetricReport.placeholderA]
|
||||
SDKMetrics.shared.cumulateReportsAndStartNewSet()
|
||||
|
||||
SDKMetrics.shared.reports[.downloadBlocks] = [SDKMetrics.BlockMetricReport.placeholderB]
|
||||
SDKMetrics.shared.cumulateReportsAndStartNewSet()
|
||||
|
||||
let summary = SDKMetrics.CumulativeSummary(
|
||||
downloadedBlocksReport: SDKMetrics.ReportSummary(minTime: 1.0, maxTime: 6.0, avgTime: 3.5),
|
||||
validatedBlocksReport: nil,
|
||||
scannedBlocksReport: nil,
|
||||
enhancementReport: nil,
|
||||
fetchUTXOsReport: nil,
|
||||
totalSyncReport: nil
|
||||
)
|
||||
|
||||
XCTAssertEqual(SDKMetrics.shared.summarizedCumulativeReports(), summary)
|
||||
|
||||
SDKMetrics.shared.disableMetrics()
|
||||
}
|
||||
}
|
||||
|
||||
extension SDKMetrics.BlockMetricReport {
|
||||
static let placeholderA = Self(
|
||||
startHeight: 1_730_000,
|
||||
progressHeight: 1_730_050,
|
||||
targetHeight: 1_730_099,
|
||||
batchSize: 10,
|
||||
startTime: Date(timeIntervalSinceReferenceDate: 0.0).timeIntervalSinceReferenceDate,
|
||||
endTime: Date(timeIntervalSinceReferenceDate: 1.0).timeIntervalSinceReferenceDate
|
||||
)
|
||||
|
||||
static let placeholderB = Self(
|
||||
startHeight: 1_730_000,
|
||||
progressHeight: 1_730_080,
|
||||
targetHeight: 1_730_099,
|
||||
batchSize: 10,
|
||||
startTime: Date(timeIntervalSinceReferenceDate: 0.0).timeIntervalSinceReferenceDate,
|
||||
endTime: Date(timeIntervalSinceReferenceDate: 6.0).timeIntervalSinceReferenceDate
|
||||
)
|
||||
}
|
||||
|
|
@ -0,0 +1,104 @@
|
|||
//
|
||||
// SynchronizerTests.swift
|
||||
//
|
||||
//
|
||||
// Created by Lukáš Korba on 13.12.2022.
|
||||
//
|
||||
|
||||
import XCTest
|
||||
@testable import ZcashLightClientKit
|
||||
@testable import TestUtils
|
||||
|
||||
class SynchronizerTests: XCTestCase {
|
||||
class MockLatestBlockHeightProvider: LatestBlockHeightProvider {
|
||||
let birthday: BlockHeight
|
||||
|
||||
init(birthday: BlockHeight) {
|
||||
self.birthday = birthday
|
||||
}
|
||||
|
||||
func latestBlockHeight(streamer: ZcashLightClientKit.CompactTxStreamerNIOClient?) throws -> ZcashLightClientKit.BlockHeight {
|
||||
self.birthday
|
||||
}
|
||||
}
|
||||
|
||||
var coordinator: TestCoordinator!
|
||||
|
||||
// swiftlint:disable:next line_length
|
||||
let seedPhrase = "wish puppy smile loan doll curve hole maze file ginger hair nose key relax knife witness cannon grab despair throw review deal slush frame"
|
||||
var birthday: BlockHeight = 1_730_000
|
||||
|
||||
@MainActor
|
||||
func testHundredBlocksSync() async throws {
|
||||
let derivationTool = DerivationTool(networkType: .mainnet)
|
||||
let seedData: Data = Data(base64Encoded: "9VDVOZZZOWWHpZtq1Ebridp3Qeux5C+HwiRR0g7Oi7HgnMs8Gfln83+/Q1NnvClcaSwM4ADFL1uZHxypEWlWXg==")!
|
||||
let seedBytes = [UInt8](seedData)
|
||||
let spendingKey = try derivationTool.deriveUnifiedSpendingKey(
|
||||
seed: seedBytes,
|
||||
accountIndex: 0
|
||||
)
|
||||
let ufvk = try derivationTool.deriveUnifiedFullViewingKey(from: spendingKey)
|
||||
let network = ZcashNetworkBuilder.network(for: .mainnet)
|
||||
let endpoint = LightWalletEndpoint(address: "lightwalletd.electriccoin.co", port: 9067, secure: true)
|
||||
|
||||
SDKMetrics.shared.enableMetrics()
|
||||
|
||||
for _ in 1...5 {
|
||||
let databases = TemporaryDbBuilder.build()
|
||||
let initializer = Initializer(
|
||||
cacheDbURL: databases.cacheDB,
|
||||
dataDbURL: databases.dataDB,
|
||||
pendingDbURL: databases.pendingDB,
|
||||
endpoint: endpoint,
|
||||
network: network,
|
||||
spendParamsURL: try __spendParamsURL(),
|
||||
outputParamsURL: try __outputParamsURL(),
|
||||
viewingKeys: [ufvk],
|
||||
walletBirthday: birthday,
|
||||
alias: "",
|
||||
loggerProxy: SampleLogger(logLevel: .debug)
|
||||
)
|
||||
|
||||
try? FileManager.default.removeItem(at: databases.cacheDB)
|
||||
try? FileManager.default.removeItem(at: databases.dataDB)
|
||||
try? FileManager.default.removeItem(at: databases.pendingDB)
|
||||
|
||||
let synchronizer = try SDKSynchronizer(initializer: initializer)
|
||||
_ = try synchronizer.prepare(with: seedBytes)
|
||||
|
||||
let syncSyncedExpectation = XCTestExpectation(description: "synchronizerSynced Expectation")
|
||||
syncSyncedExpectation.subscribe(to: .synchronizerSynced, object: nil)
|
||||
|
||||
let internalSyncProgress = InternalSyncProgress(storage: UserDefaults.standard)
|
||||
await internalSyncProgress.rewind(to: birthday)
|
||||
await (synchronizer.blockProcessor.service as? LightWalletGRPCService)?.latestBlockHeightProvider = MockLatestBlockHeightProvider(birthday: self.birthday + 99)
|
||||
|
||||
try synchronizer.start()
|
||||
|
||||
wait(for: [syncSyncedExpectation], timeout: 100)
|
||||
|
||||
SDKMetrics.shared.cumulateReportsAndStartNewSet()
|
||||
}
|
||||
|
||||
if let cumulativeSummary = SDKMetrics.shared.summarizedCumulativeReports() {
|
||||
let downloadedBlocksReport = cumulativeSummary.downloadedBlocksReport ?? .zero
|
||||
let validatedBlocksReport = cumulativeSummary.validatedBlocksReport ?? .zero
|
||||
let scannedBlocksReport = cumulativeSummary.scannedBlocksReport ?? .zero
|
||||
let enhancementReport = cumulativeSummary.enhancementReport ?? .zero
|
||||
let fetchUTXOsReport = cumulativeSummary.fetchUTXOsReport ?? .zero
|
||||
let totalSyncReport = cumulativeSummary.totalSyncReport ?? .zero
|
||||
|
||||
LoggerProxy.debug("""
|
||||
testHundredBlocksSync() SUMMARY min max avg REPORT:
|
||||
downloadedBlocksTimes: min: \(downloadedBlocksReport.minTime) max: \(downloadedBlocksReport.maxTime) avg: \(downloadedBlocksReport.avgTime)
|
||||
validatedBlocksTimes: min: \(validatedBlocksReport.minTime) max: \(validatedBlocksReport.maxTime) avg: \(validatedBlocksReport.avgTime)
|
||||
scannedBlocksTimes: min: \(scannedBlocksReport.minTime) max: \(scannedBlocksReport.maxTime) avg: \(scannedBlocksReport.avgTime)
|
||||
enhancementTimes: min: \(enhancementReport.minTime) max: \(enhancementReport.maxTime) avg: \(enhancementReport.avgTime)
|
||||
fetchUTXOsTimes: min: \(fetchUTXOsReport.minTime) max: \(fetchUTXOsReport.maxTime) avg: \(fetchUTXOsReport.avgTime)
|
||||
totalSyncTimes: min: \(totalSyncReport.minTime) max: \(totalSyncReport.maxTime) avg: \(totalSyncReport.avgTime)
|
||||
""")
|
||||
}
|
||||
|
||||
SDKMetrics.shared.disableMetrics()
|
||||
}
|
||||
}
|
||||
|
|
@ -0,0 +1,116 @@
|
|||
# Performance Testing
|
||||
### Intro
|
||||
Benchmarking the SDK is one of the key focuses of `SDKMetrics` API. The most important operation of the SDK is the ability to synchronize blocks in order to see transactions, right balances and to send & receive funds. In short, be in sync with the mainnet blockchain. Synchronization consists of several sub-operations like downloading the blocks, validating & scanning, etc.
|
||||
|
||||
### Benchmarking the Synchronization
|
||||
The initial work on benchmarking/performance testing allows us to properly measure times spent in sub-operations of a synchronization. There will be iterations and enhancements and ideally fully automated solution one day but for now we rely on manual approach.
|
||||
|
||||
### SDKMetrics
|
||||
`SDKMetrics` is the public interface on the SDK side allowing users to get the synchronization related metrics. It's a shared singleton and you can access it via
|
||||
```swift
|
||||
SDKMetrics.shared
|
||||
```
|
||||
By default the gathering of the data is turned of so anything reported inside the SDK is simply ignored. You need to call
|
||||
```swift
|
||||
SDKMetrics.shared.enableMetrics()
|
||||
```
|
||||
in order to allow `SDKMetrics` to actually collect the RAW data. There's a counterpart API for the enablement, called
|
||||
```swift
|
||||
SDKMetrics.shared.disableMetrics()
|
||||
```
|
||||
This method turns the `SDKMetrics` off from collecting and also flushes all the so far collected RAW data.
|
||||
Like we said, the SDK is automatically reporting sub-operation metrics. The reports are collected and held in memory, split by the operation:
|
||||
```swift
|
||||
enum Operation {
|
||||
case downloadBlocks // download of the blocks
|
||||
case validateBlocks // validation of the downloaded blocks
|
||||
case scanBlocks // scanning of the downloaded blocks
|
||||
case enhancement // enhancement of the transactions
|
||||
case fetchUTXOs // fetching the UTXOs
|
||||
}
|
||||
```
|
||||
Every report is represented by a struct:
|
||||
```swift
|
||||
struct BlockMetricReport: Equatable {
|
||||
startHeight: BlockHeight // start of the range to be processed
|
||||
progressHeight: BlockHeight // latest processed height
|
||||
targetHeight: BlockHeight // end of the range to be processed
|
||||
batchSize: Int // size of the batch to be processed
|
||||
startTime: TimeInterval // when the operation started
|
||||
endTime: TimeInterval // when the operation finished
|
||||
duration: TimeInterval // computed property to provide duration
|
||||
}
|
||||
```
|
||||
`SDKMetrics` holds the reports in a dictionary where keys are the operations. You can receive the data via either of the following methods.
|
||||
```swift
|
||||
// Get all reports for the specific Operation
|
||||
SDKMetrics.shared.popBlock(operation: Operation, flush: Bool = false) -> [BlockMetricReport]?
|
||||
|
||||
// Get the whole dictionary of collected data
|
||||
SDKMetrics.shared.popAllBlockReports(flush: Bool = false) -> [Operation : [BlockMetricReport]]
|
||||
```
|
||||
Notice `flush` to be set to false by default. Collection the data leaves it in memory but you can clear it out of the memory by setting `flush` to `true`. Such option is handy when you plan to start to collect a new set of data.
|
||||
|
||||
These two `pop` methods simply returns RAW data from the `SDKMetrics` so post-processing of the data is up to the caller. There are extension methods that help with the accumulation of reports and provide decent post-processing for typical use cases though.
|
||||
|
||||
### SDKMetrics extension
|
||||
Post-processing the array of reports per `Operation` or more general a dictionary of all arrays of reports may be time consuming, especially when you need to know just the times `Operation`s have taken. For this specific needs we introduce `CumulativeSummary` struct:
|
||||
```swift
|
||||
struct CumulativeSummary: Equatable {
|
||||
downloadedBlocksReport: ReportSummary?
|
||||
validatedBlocksReport: ReportSummary?
|
||||
scannedBlocksReport: ReportSummary?
|
||||
enhancementReport: ReportSummary?
|
||||
fetchUTXOsReport: ReportSummary?
|
||||
totalSyncReport: ReportSummary?
|
||||
```
|
||||
where `ReportSummary` represents:
|
||||
```swift
|
||||
struct ReportSummary: Equatable {
|
||||
minTime: TimeInterval
|
||||
maxTime: TimeInterval
|
||||
avgTime: TimeInterval
|
||||
```
|
||||
As you can see `CumulativeSummary` basically holds `min`, `max` and `avg` times per `Operation`. To generate such summary you call:
|
||||
```swift
|
||||
// Get the cumulative summary of the collected data
|
||||
SDKMetrics.shared.cumulativeSummary() -> CumulativeSummary
|
||||
```
|
||||
There is a specific use case we want to mention, imagine you want to run a performance test that calls synchronization several times and you want to measure all runs separately and process runs afterwards. You either call `cumulativeSummary()` and re-enable the metrics to flush the data out and post-process collected summaries on your own or you can take advantage of 2 more methods available:
|
||||
```swift
|
||||
// Generates `CumulativeSummary` and stores it in memory & clears out data
|
||||
SDKMetrics.shared.cumulateReportsAndStartNewSet()
|
||||
|
||||
// Merges all cumulativeSummaries into one
|
||||
SDKMetrics.shared.summarizedCumulativeReports() -> CumulativeSummary?
|
||||
```
|
||||
So typical use case of these methods is sketched in the following pseudo code
|
||||
```swift
|
||||
SDKMetrics.shared.enableMetrics()
|
||||
|
||||
for run in 1...X {
|
||||
// ensure fresh start of synchronization
|
||||
|
||||
// synchronize
|
||||
|
||||
// collect data for this run and start new set
|
||||
SDKMetrics.shared.cumulateReportsAndStartNewSet()
|
||||
}
|
||||
|
||||
// collect final data as a merge of all runs
|
||||
let finalSummary = SDKMetrics.shared.summarizedCumulativeReports()
|
||||
|
||||
SDKMetrics.shared.disableMetrics()
|
||||
```
|
||||
Printed out example of the `finalSummary`:
|
||||
```
|
||||
downloadedBlocksTimes: min: 0.002303004264831543 max: 0.9062199592590332 avg: 0.14520481750369074
|
||||
validatedBlocksTimes: min: 0.01760399341583252 max: 0.019036054611206055 avg: 0.0178409144282341
|
||||
scannedBlocksTimes: min: 0.045277953147888184 max: 0.5136369466781616 avg: 0.2530662305653095
|
||||
enhancementTimes: min: 0.0 max: 0.0 avg: 0.0
|
||||
fetchUTXOsTimes: min: 1.9073486328125e-06 max: 2.09808349609375e-05 avg: 3.166496753692627e-06
|
||||
totalSyncTimes: min: 7.222689986228943 max: 10.718868017196655 avg: 8.997062936425209
|
||||
```
|
||||
|
||||
### Performance tests
|
||||
We encourage you to visit `Tests/PerformanceTests/` folder and check `SynchronizerTests` where we do exactly what is mentioned in this doc. We run synchronization for specific range of 100 blocks 5 times, measure every run separately and merge results together in the end. The `SDKMetrics` and `SynchronizerTests` lay down foundations for the future automatization of performance testing.
|
||||
Loading…
Reference in New Issue