From 986c32c50d45f53409624ffc9e3082eb40082084 Mon Sep 17 00:00:00 2001 From: Alex Gherghisan Date: Fri, 5 Jan 2024 15:47:47 +0000 Subject: [PATCH 1/7] feat: add new metrics --- .../standard_indexed_tree.ts | 12 +++++ .../src/standard_tree/standard_tree.ts | 12 +++++ yarn-project/merkle-tree/src/tree_base.ts | 4 ++ .../pxe/src/pxe_service/pxe_service.ts | 8 +++ .../scripts/src/benchmarks/aggregate.ts | 25 ++++++++++ .../src/sequencer/public_processor.ts | 14 +++++- yarn-project/types/src/logs/log_filter.ts | 2 +- yarn-project/types/src/stats/metrics.ts | 27 +++++++++- yarn-project/types/src/stats/stats.ts | 49 ++++++++++++++++++- yarn-project/types/src/tx/tx.ts | 4 +- 10 files changed, 152 insertions(+), 5 deletions(-) diff --git a/yarn-project/merkle-tree/src/standard_indexed_tree/standard_indexed_tree.ts b/yarn-project/merkle-tree/src/standard_indexed_tree/standard_indexed_tree.ts index ff256dfcbf5a..0ffb87dcaa64 100644 --- a/yarn-project/merkle-tree/src/standard_indexed_tree/standard_indexed_tree.ts +++ b/yarn-project/merkle-tree/src/standard_indexed_tree/standard_indexed_tree.ts @@ -1,7 +1,9 @@ import { toBigIntBE, toBufferBE } from '@aztec/foundation/bigint-buffer'; import { createDebugLogger } from '@aztec/foundation/log'; +import { Timer } from '@aztec/foundation/timer'; import { IndexedTreeLeaf, IndexedTreeLeafPreimage } from '@aztec/foundation/trees'; import { Hasher, SiblingPath } from '@aztec/types'; +import { TreeInsertionStats } from '@aztec/types/stats'; import { LevelUp } from 'levelup'; @@ -507,6 +509,7 @@ export class StandardIndexedTree extends TreeBase implements IndexedTree { leaves: Buffer[], subtreeHeight: SubtreeHeight, ): Promise> { + const timer = new Timer(); const insertedKeys = new Map(); const emptyLowLeafWitness = getEmptyLowLeafWitness(this.getDepth() as TreeHeight, this.leafPreimageFactory); // Accumulators @@ -603,6 +606,15 @@ export class StandardIndexedTree extends TreeBase implements IndexedTree { // inclusion. See {@link encodeLeaf} for a more through param explanation. await this.encodeAndAppendLeaves(pendingInsertionSubtree, false); + this.log(`Inserted ${leaves.length} leaves into ${this.getName()} tree`, { + eventName: 'tree-insertion', + duration: timer.ms(), + batchSize: leaves.length, + treeName: this.getName(), + treeDepth: this.getDepth(), + treeType: 'indexed', + } satisfies TreeInsertionStats); + return { lowLeavesWitnessData: lowLeavesWitnesses, sortedNewLeaves: sortedDescendingLeafTuples.map(leafTuple => leafTuple.leaf.toBuffer()), diff --git a/yarn-project/merkle-tree/src/standard_tree/standard_tree.ts b/yarn-project/merkle-tree/src/standard_tree/standard_tree.ts index 55b4f5324690..3c48cfd22122 100644 --- a/yarn-project/merkle-tree/src/standard_tree/standard_tree.ts +++ b/yarn-project/merkle-tree/src/standard_tree/standard_tree.ts @@ -1,3 +1,6 @@ +import { Timer } from '@aztec/foundation/timer'; +import { TreeInsertionStats } from '@aztec/types/stats'; + import { AppendOnlySnapshotBuilder, TreeSnapshot } from '../index.js'; import { AppendOnlyTree } from '../interfaces/append_only_tree.js'; import { TreeBase } from '../tree_base.js'; @@ -14,7 +17,16 @@ export class StandardTree extends TreeBase implements AppendOnlyTree { * @returns Empty promise. */ public async appendLeaves(leaves: Buffer[]): Promise { + const timer = new Timer(); await super.appendLeaves(leaves); + this.log(`Inserted ${leaves.length} leaves into ${this.getName()} tree`, { + eventName: 'tree-insertion', + duration: timer.ms(), + batchSize: leaves.length, + treeName: this.getName(), + treeDepth: this.getDepth(), + treeType: 'append-only', + } satisfies TreeInsertionStats); } public snapshot(block: number): Promise { diff --git a/yarn-project/merkle-tree/src/tree_base.ts b/yarn-project/merkle-tree/src/tree_base.ts index 291ac258082b..befad55ae727 100644 --- a/yarn-project/merkle-tree/src/tree_base.ts +++ b/yarn-project/merkle-tree/src/tree_base.ts @@ -1,4 +1,5 @@ import { toBigIntLE, toBufferLE } from '@aztec/foundation/bigint-buffer'; +import { DebugLogger, createDebugLogger } from '@aztec/foundation/log'; import { Hasher, SiblingPath } from '@aztec/types'; import { LevelUp, LevelUpChain } from 'levelup'; @@ -36,6 +37,7 @@ export abstract class TreeBase implements MerkleTree { private root!: Buffer; private zeroHashes: Buffer[] = []; private cache: { [key: string]: Buffer } = {}; + protected log: DebugLogger; public constructor( protected db: LevelUp, @@ -58,6 +60,8 @@ export abstract class TreeBase implements MerkleTree { this.root = root ? root : current; this.maxIndex = 2n ** BigInt(depth) - 1n; + + this.log = createDebugLogger(`aztec:merkle-tree:${name}`); } /** diff --git a/yarn-project/pxe/src/pxe_service/pxe_service.ts b/yarn-project/pxe/src/pxe_service/pxe_service.ts index db3a905ee7b4..19327288aa98 100644 --- a/yarn-project/pxe/src/pxe_service/pxe_service.ts +++ b/yarn-project/pxe/src/pxe_service/pxe_service.ts @@ -23,6 +23,7 @@ import { padArrayEnd } from '@aztec/foundation/collection'; import { Fr } from '@aztec/foundation/fields'; import { SerialQueue } from '@aztec/foundation/fifo'; import { DebugLogger, createDebugLogger } from '@aztec/foundation/log'; +import { Timer } from '@aztec/foundation/timer'; import { NoirWasmVersion } from '@aztec/noir-compiler/versions'; import { AuthWitness, @@ -52,6 +53,7 @@ import { getNewContractPublicFunctions, isNoirCallStackUnresolved, } from '@aztec/types'; +import { TxPrivatePartProcessedStats } from '@aztec/types/stats'; import { PXEServiceConfig, getPackageInfo } from '../config/index.js'; import { ContractDataOracle } from '../contract_data_oracle/index.js'; @@ -353,7 +355,13 @@ export class PXEService implements PXE { const deployedContractAddress = txRequest.txContext.isContractDeploymentTx ? txRequest.origin : undefined; const newContract = deployedContractAddress ? await this.db.getContract(deployedContractAddress) : undefined; + const timer = new Timer(); const tx = await this.#simulateAndProve(txRequest, newContract); + this.log(`Processed private part of ${tx.data.end.newNullifiers[0]}`, { + eventName: 'tx-private-part-processed', + duration: timer.ms(), + ...tx.getStats(), + } satisfies TxPrivatePartProcessedStats); if (simulatePublic) { await this.#simulatePublicCalls(tx); } diff --git a/yarn-project/scripts/src/benchmarks/aggregate.ts b/yarn-project/scripts/src/benchmarks/aggregate.ts index 3dab2f4f54fb..d5a463e62d71 100644 --- a/yarn-project/scripts/src/benchmarks/aggregate.ts +++ b/yarn-project/scripts/src/benchmarks/aggregate.ts @@ -24,7 +24,10 @@ import { NodeSyncedChainHistoryStats, NoteProcessorCaughtUpStats, Stats, + TreeInsertionStats, TxAddedToPoolStats, + TxPrivatePartProcessedStats, + TxPublicPartProcessedStats, } from '@aztec/types/stats'; import * as fs from 'fs'; @@ -151,6 +154,22 @@ function processTxAddedToPool(entry: TxAddedToPoolStats, results: BenchmarkColle append(results, 'tx_size_in_bytes', entry.newContractCount, entry.size); } +/** Process entries for events tx-private-part-processed, grouped by new commitments */ +function processTxPrivatePart(entry: TxPrivatePartProcessedStats, results: BenchmarkCollectedResults) { + append(results, 'tx_private_process_time_ms', entry.newCommitmentCount, entry.duration); +} + +/** Process entries for events tx-public-part-processed, grouped by public data writes */ +function processTxPublicPart(entry: TxPublicPartProcessedStats, results: BenchmarkCollectedResults) { + append(results, 'tx_public_process_time_ms', entry.publicDataUpdateRequests, entry.duration); +} + +/** Process a tree insertion event and updates results */ +function processTreeInsertion(entry: TreeInsertionStats, results: BenchmarkCollectedResults) { + const bucket = entry.treeName + '_batch_' + entry.batchSize + '_leaves'; + append(results, 'tree_insertion_time_in_ms', bucket, entry.duration); +} + /** Processes a parsed entry from a log-file and updates results */ function processEntry(entry: Stats, results: BenchmarkCollectedResults) { switch (entry.eventName) { @@ -168,6 +187,12 @@ function processEntry(entry: Stats, results: BenchmarkCollectedResults) { return processNodeSyncedChain(entry, results); case 'tx-added-to-pool': return processTxAddedToPool(entry, results); + case 'tx-private-part-processed': + return processTxPrivatePart(entry, results); + case 'tx-public-part-processed': + return processTxPublicPart(entry, results); + case 'tree-insertion': + return processTreeInsertion(entry, results); default: return; } diff --git a/yarn-project/sequencer-client/src/sequencer/public_processor.ts b/yarn-project/sequencer-client/src/sequencer/public_processor.ts index fba66b0b7979..7012b2ee02b4 100644 --- a/yarn-project/sequencer-client/src/sequencer/public_processor.ts +++ b/yarn-project/sequencer-client/src/sequencer/public_processor.ts @@ -44,7 +44,9 @@ import { computeVarArgsHash } from '@aztec/circuits.js/abis'; import { arrayNonEmptyLength, isArrayEmpty, padArrayEnd } from '@aztec/foundation/collection'; import { createDebugLogger } from '@aztec/foundation/log'; import { to2Fields } from '@aztec/foundation/serialize'; +import { Timer } from '@aztec/foundation/timer'; import { ContractDataSource, FunctionL2Logs, L1ToL2MessageSource, MerkleTreeId, Tx } from '@aztec/types'; +import { TxPublicPartProcessedStats } from '@aztec/types/stats'; import { MerkleTreeOperations } from '@aztec/world-state'; import { getVerificationKeys } from '../index.js'; @@ -159,12 +161,22 @@ export class PublicProcessor { protected async processTx(tx: Tx): Promise { if (!isArrayEmpty(tx.data.end.publicCallStack, item => item.isEmpty())) { + const timer = new Timer(); + const [publicKernelOutput, publicKernelProof, newUnencryptedFunctionLogs] = await this.processEnqueuedPublicCalls( tx, ); tx.unencryptedLogs.addFunctionLogs(newUnencryptedFunctionLogs); - return makeProcessedTx(tx, publicKernelOutput, publicKernelProof); + const processedTransaction = await makeProcessedTx(tx, publicKernelOutput, publicKernelProof); + this.log(`Processed public part of ${tx.data.end.newNullifiers[0]}`, { + eventName: 'tx-public-part-processed', + duration: timer.ms(), + publicDataUpdateRequests: processedTransaction.data.end.publicDataUpdateRequests.length ?? 0, + ...tx.getStats(), + } satisfies TxPublicPartProcessedStats); + + return processedTransaction; } else { return makeProcessedTx(tx); } diff --git a/yarn-project/types/src/logs/log_filter.ts b/yarn-project/types/src/logs/log_filter.ts index a1448527edda..c77c73b2d907 100644 --- a/yarn-project/types/src/logs/log_filter.ts +++ b/yarn-project/types/src/logs/log_filter.ts @@ -1,6 +1,6 @@ import { AztecAddress, FunctionSelector } from '@aztec/circuits.js'; -import { TxHash } from '../tx/index.js'; +import { TxHash } from '../tx/tx_hash.js'; import { LogId } from './log_id.js'; /** diff --git a/yarn-project/types/src/stats/metrics.ts b/yarn-project/types/src/stats/metrics.ts index 235e6284ef2c..03a9fbdb0bb6 100644 --- a/yarn-project/types/src/stats/metrics.ts +++ b/yarn-project/types/src/stats/metrics.ts @@ -1,7 +1,14 @@ import { StatsEventName } from './stats.js'; /** How a metric is grouped in benchmarks: by block size, by length of chain processed, or by circuit name. */ -export type MetricGroupBy = 'block-size' | 'chain-length' | 'circuit-name' | 'contract-count'; +export type MetricGroupBy = + | 'block-size' + | 'chain-length' + | 'circuit-name' + | 'contract-count' + | 'tree-name' + | 'private-writes' + | 'public-writes'; /** Definition of a metric to track in benchmarks. */ export interface Metric { @@ -127,6 +134,24 @@ export const Metrics = [ description: 'Size of txs received in the mempool.', events: ['tx-added-to-pool'], }, + { + name: 'tx_private_process_time_ms', + groupBy: 'private-writes', + description: 'Time to process the private part of a tx.', + events: ['tx-private-part-processed'], + }, + { + name: 'tx_public_process_time_ms', + groupBy: 'public-writes', + description: 'Time to process the public part of a tx.', + events: ['tx-private-part-processed'], + }, + { + name: 'tree_insertion_time_in_ms', + groupBy: 'tree-name', + description: 'Time to insert a batch of leaves into a tree', + events: ['tree-insertion'], + }, ] as const satisfies readonly Metric[]; /** Metric definitions to track from benchmarks. */ diff --git a/yarn-project/types/src/stats/stats.ts b/yarn-project/types/src/stats/stats.ts index 22c7373389a1..c4ea385ed6c8 100644 --- a/yarn-project/types/src/stats/stats.ts +++ b/yarn-project/types/src/stats/stats.ts @@ -138,6 +138,50 @@ export type TxStats = { newContractDataSize: number; /** Number of new contracts deployed in this tx. */ newContractCount: number; + /** comm */ + newCommitmentCount: number; + /** a */ + newNullifierCount: number; +}; + +/** + * Stats for a tx that has been processed by the public processor. + */ +export type TxPrivatePartProcessedStats = { + /** Name of the event. */ + eventName: 'tx-private-part-processed'; + /** Duration in ms. */ + duration: number; +} & TxStats; + +/** + * Stats for a tx that has been processed by the public processor. + */ +export type TxPublicPartProcessedStats = { + /** Name of the event. */ + eventName: 'tx-public-part-processed'; + /** Duration in ms. */ + duration: number; + /** Count of how many public writes this tx has made. Acts as a proxy for how 'heavy' this tx */ + publicDataUpdateRequests: number; +} & TxStats; + +/** + * Stats for tree insertions + */ +export type TreeInsertionStats = { + /** Name of the event. */ + eventName: 'tree-insertion'; + /** Duration in ms. */ + duration: number; + /** The size of the insertion batch */ + batchSize: number; + /** The tree name */ + treeName: string; + /** The tree depth */ + treeDepth: number; + /** Tree type */ + treeType: 'append-only' | 'indexed'; }; /** A new tx was added to the tx pool. */ @@ -154,7 +198,10 @@ export type Stats = | L2BlockBuiltStats | L2BlockHandledStats | NoteProcessorCaughtUpStats - | TxAddedToPoolStats; + | TxAddedToPoolStats + | TxPrivatePartProcessedStats + | TxPublicPartProcessedStats + | TreeInsertionStats; /** Set of event names across emitted stats. */ export type StatsEventName = Stats['eventName']; diff --git a/yarn-project/types/src/tx/tx.ts b/yarn-project/types/src/tx/tx.ts index f9c57272df56..c8d9c9f7977c 100644 --- a/yarn-project/types/src/tx/tx.ts +++ b/yarn-project/types/src/tx/tx.ts @@ -5,7 +5,7 @@ import { BufferReader, Tuple } from '@aztec/foundation/serialize'; import { ExtendedContractData } from '../contract_data.js'; import { GetUnencryptedLogsResponse } from '../logs/get_unencrypted_logs_response.js'; -import { L2LogsSource } from '../logs/index.js'; +import { L2LogsSource } from '../logs/l2_logs_source.js'; import { TxL2Logs } from '../logs/tx_l2_logs.js'; import { TxStats } from '../stats/stats.js'; import { TxHash } from './tx_hash.js'; @@ -168,6 +168,8 @@ export class Tx { unencryptedLogSize: this.unencryptedLogs.getSerializedLength(), newContractCount: this.newContracts.filter(c => !c.isEmpty()).length, newContractDataSize: this.newContracts.map(c => c.toBuffer().length).reduce((a, b) => a + b, 0), + newCommitmentCount: this.data!.end.newCommitments.filter(c => !c.isEmpty()).length, + newNullifierCount: this.data!.end.newNullifiers.filter(c => !c.isEmpty()).length, proofSize: this.proof.buffer.length, size: this.toBuffer().length, }; From d1370a7086e9e15cfcbd56fb38a480e0e2cf59a4 Mon Sep 17 00:00:00 2001 From: Alex Gherghisan Date: Mon, 8 Jan 2024 10:32:48 +0000 Subject: [PATCH 2/7] refactor: status names --- .../pxe/src/pxe_service/pxe_service.ts | 6 +++--- .../scripts/src/benchmarks/aggregate.ts | 20 +++++++++---------- .../src/sequencer/public_processor.ts | 6 +++--- yarn-project/types/src/stats/metrics.ts | 8 ++++---- yarn-project/types/src/stats/stats.ts | 12 +++++------ 5 files changed, 26 insertions(+), 26 deletions(-) diff --git a/yarn-project/pxe/src/pxe_service/pxe_service.ts b/yarn-project/pxe/src/pxe_service/pxe_service.ts index 19327288aa98..51d9df89fab5 100644 --- a/yarn-project/pxe/src/pxe_service/pxe_service.ts +++ b/yarn-project/pxe/src/pxe_service/pxe_service.ts @@ -53,7 +53,7 @@ import { getNewContractPublicFunctions, isNoirCallStackUnresolved, } from '@aztec/types'; -import { TxPrivatePartProcessedStats } from '@aztec/types/stats'; +import { TxPXEProcessingStats } from '@aztec/types/stats'; import { PXEServiceConfig, getPackageInfo } from '../config/index.js'; import { ContractDataOracle } from '../contract_data_oracle/index.js'; @@ -358,10 +358,10 @@ export class PXEService implements PXE { const timer = new Timer(); const tx = await this.#simulateAndProve(txRequest, newContract); this.log(`Processed private part of ${tx.data.end.newNullifiers[0]}`, { - eventName: 'tx-private-part-processed', + eventName: 'tx-pxe-processing', duration: timer.ms(), ...tx.getStats(), - } satisfies TxPrivatePartProcessedStats); + } satisfies TxPXEProcessingStats); if (simulatePublic) { await this.#simulatePublicCalls(tx); } diff --git a/yarn-project/scripts/src/benchmarks/aggregate.ts b/yarn-project/scripts/src/benchmarks/aggregate.ts index d5a463e62d71..36cb13032129 100644 --- a/yarn-project/scripts/src/benchmarks/aggregate.ts +++ b/yarn-project/scripts/src/benchmarks/aggregate.ts @@ -26,8 +26,8 @@ import { Stats, TreeInsertionStats, TxAddedToPoolStats, - TxPrivatePartProcessedStats, - TxPublicPartProcessedStats, + TxPXEProcessingStats, + TxSequencerProcessingStats, } from '@aztec/types/stats'; import * as fs from 'fs'; @@ -155,13 +155,13 @@ function processTxAddedToPool(entry: TxAddedToPoolStats, results: BenchmarkColle } /** Process entries for events tx-private-part-processed, grouped by new commitments */ -function processTxPrivatePart(entry: TxPrivatePartProcessedStats, results: BenchmarkCollectedResults) { - append(results, 'tx_private_process_time_ms', entry.newCommitmentCount, entry.duration); +function processTxPXEProcessingStats(entry: TxPXEProcessingStats, results: BenchmarkCollectedResults) { + append(results, 'tx_pxe_processing_time_ms', entry.newCommitmentCount, entry.duration); } /** Process entries for events tx-public-part-processed, grouped by public data writes */ -function processTxPublicPart(entry: TxPublicPartProcessedStats, results: BenchmarkCollectedResults) { - append(results, 'tx_public_process_time_ms', entry.publicDataUpdateRequests, entry.duration); +function processTxSequencerProcessingStats(entry: TxSequencerProcessingStats, results: BenchmarkCollectedResults) { + append(results, 'tx_sequencer_processing_time_ms', entry.publicDataUpdateRequests, entry.duration); } /** Process a tree insertion event and updates results */ @@ -187,10 +187,10 @@ function processEntry(entry: Stats, results: BenchmarkCollectedResults) { return processNodeSyncedChain(entry, results); case 'tx-added-to-pool': return processTxAddedToPool(entry, results); - case 'tx-private-part-processed': - return processTxPrivatePart(entry, results); - case 'tx-public-part-processed': - return processTxPublicPart(entry, results); + case 'tx-pxe-processing': + return processTxPXEProcessingStats(entry, results); + case 'tx-sequencer-processing': + return processTxSequencerProcessingStats(entry, results); case 'tree-insertion': return processTreeInsertion(entry, results); default: diff --git a/yarn-project/sequencer-client/src/sequencer/public_processor.ts b/yarn-project/sequencer-client/src/sequencer/public_processor.ts index 7012b2ee02b4..b1d8875bda0e 100644 --- a/yarn-project/sequencer-client/src/sequencer/public_processor.ts +++ b/yarn-project/sequencer-client/src/sequencer/public_processor.ts @@ -46,7 +46,7 @@ import { createDebugLogger } from '@aztec/foundation/log'; import { to2Fields } from '@aztec/foundation/serialize'; import { Timer } from '@aztec/foundation/timer'; import { ContractDataSource, FunctionL2Logs, L1ToL2MessageSource, MerkleTreeId, Tx } from '@aztec/types'; -import { TxPublicPartProcessedStats } from '@aztec/types/stats'; +import { TxSequencerProcessingStats } from '@aztec/types/stats'; import { MerkleTreeOperations } from '@aztec/world-state'; import { getVerificationKeys } from '../index.js'; @@ -170,11 +170,11 @@ export class PublicProcessor { const processedTransaction = await makeProcessedTx(tx, publicKernelOutput, publicKernelProof); this.log(`Processed public part of ${tx.data.end.newNullifiers[0]}`, { - eventName: 'tx-public-part-processed', + eventName: 'tx-sequencer-processing', duration: timer.ms(), publicDataUpdateRequests: processedTransaction.data.end.publicDataUpdateRequests.length ?? 0, ...tx.getStats(), - } satisfies TxPublicPartProcessedStats); + } satisfies TxSequencerProcessingStats); return processedTransaction; } else { diff --git a/yarn-project/types/src/stats/metrics.ts b/yarn-project/types/src/stats/metrics.ts index 03a9fbdb0bb6..b5b8bd4948e5 100644 --- a/yarn-project/types/src/stats/metrics.ts +++ b/yarn-project/types/src/stats/metrics.ts @@ -135,16 +135,16 @@ export const Metrics = [ events: ['tx-added-to-pool'], }, { - name: 'tx_private_process_time_ms', + name: 'tx_pxe_processing_time_ms', groupBy: 'private-writes', description: 'Time to process the private part of a tx.', - events: ['tx-private-part-processed'], + events: ['tx-pxe-processing'], }, { - name: 'tx_public_process_time_ms', + name: 'tx_sequencer_processing_time_ms', groupBy: 'public-writes', description: 'Time to process the public part of a tx.', - events: ['tx-private-part-processed'], + events: ['tx-sequencer-processing'], }, { name: 'tree_insertion_time_in_ms', diff --git a/yarn-project/types/src/stats/stats.ts b/yarn-project/types/src/stats/stats.ts index c4ea385ed6c8..19a0535c9222 100644 --- a/yarn-project/types/src/stats/stats.ts +++ b/yarn-project/types/src/stats/stats.ts @@ -147,9 +147,9 @@ export type TxStats = { /** * Stats for a tx that has been processed by the public processor. */ -export type TxPrivatePartProcessedStats = { +export type TxPXEProcessingStats = { /** Name of the event. */ - eventName: 'tx-private-part-processed'; + eventName: 'tx-pxe-processing'; /** Duration in ms. */ duration: number; } & TxStats; @@ -157,9 +157,9 @@ export type TxPrivatePartProcessedStats = { /** * Stats for a tx that has been processed by the public processor. */ -export type TxPublicPartProcessedStats = { +export type TxSequencerProcessingStats = { /** Name of the event. */ - eventName: 'tx-public-part-processed'; + eventName: 'tx-sequencer-processing'; /** Duration in ms. */ duration: number; /** Count of how many public writes this tx has made. Acts as a proxy for how 'heavy' this tx */ @@ -199,8 +199,8 @@ export type Stats = | L2BlockHandledStats | NoteProcessorCaughtUpStats | TxAddedToPoolStats - | TxPrivatePartProcessedStats - | TxPublicPartProcessedStats + | TxPXEProcessingStats + | TxSequencerProcessingStats | TreeInsertionStats; /** Set of event names across emitted stats. */ From c10be24a81151eca85e9d2a91e0abc5a6d7bbc8b Mon Sep 17 00:00:00 2001 From: Alex Gherghisan Date: Mon, 8 Jan 2024 10:52:04 +0000 Subject: [PATCH 3/7] feat: add tree metrics to github comment --- yarn-project/scripts/src/benchmarks/aggregate.ts | 8 ++++++-- yarn-project/scripts/src/benchmarks/markdown.ts | 6 +++++- yarn-project/types/src/stats/metrics.ts | 14 ++++++++++---- 3 files changed, 21 insertions(+), 7 deletions(-) diff --git a/yarn-project/scripts/src/benchmarks/aggregate.ts b/yarn-project/scripts/src/benchmarks/aggregate.ts index 36cb13032129..bb0dbb21fe1a 100644 --- a/yarn-project/scripts/src/benchmarks/aggregate.ts +++ b/yarn-project/scripts/src/benchmarks/aggregate.ts @@ -166,8 +166,12 @@ function processTxSequencerProcessingStats(entry: TxSequencerProcessingStats, re /** Process a tree insertion event and updates results */ function processTreeInsertion(entry: TreeInsertionStats, results: BenchmarkCollectedResults) { - const bucket = entry.treeName + '_batch_' + entry.batchSize + '_leaves'; - append(results, 'tree_insertion_time_in_ms', bucket, entry.duration); + const bucket = entry.batchSize; + if (entry.treeType === 'append-only') { + append(results, 'batch_insert_into_append_only_tree_ms', bucket, entry.duration); + } else if (entry.treeType === 'indexed') { + append(results, 'batch_insert_into_indexed_tree_ms', bucket, entry.duration); + } } /** Processes a parsed entry from a log-file and updates results */ diff --git a/yarn-project/scripts/src/benchmarks/markdown.ts b/yarn-project/scripts/src/benchmarks/markdown.ts index 7b8b843fb365..fa4c340dffed 100644 --- a/yarn-project/scripts/src/benchmarks/markdown.ts +++ b/yarn-project/scripts/src/benchmarks/markdown.ts @@ -180,6 +180,7 @@ export function getMarkdown() { const metricsByChainLength = Metrics.filter(m => m.groupBy === 'chain-length').map(m => m.name); const metricsByCircuitName = Metrics.filter(m => m.groupBy === 'circuit-name').map(m => m.name); const metricsByContractCount = Metrics.filter(m => m.groupBy === 'contract-count').map(m => m.name); + const metricsByLeafCount = Metrics.filter(m => m.groupBy === 'leaf-count').map(m => m.name); const baseHash = process.env.BASE_COMMIT_HASH; const baseUrl = baseHash && `[\`${baseHash.slice(0, 8)}\`](${S3_URL}/benchmarks-v1/master/${baseHash}.json)`; @@ -202,7 +203,7 @@ ${getWarningsSummary(benchmark, baseBenchmark)} Detailed results -All benchmarks are run on txs on the \`Benchmarking\` contract on the repository. Each tx consists of a batch call to \`create_note\` and \`increment_balance\`, which guarantees that each tx has a private call, a nested private call, a public call, and a nested public call, as well as an emitted private note, an unencrypted log, and public storage read and write. +All benchmarks are run on txs on the \`Benchmarking\` contract on the repository. Each tx consists of a batch call to \`create_note\` and \`increment_balance\`, which guarantees that each tx has a private call, a nested private call, a public call, and a nested public call, as well as an emitted private note, an unencrypted log, and public storage read and write. ${prSourceDataText} ${baseCommitText} @@ -221,6 +222,9 @@ ${getTableContent(pick(benchmark, metricsByChainLength), baseBenchmark, 'blocks' Stats on running time and I/O sizes collected for every circuit run across all benchmarks. ${getTableContent(transpose(pick(benchmark, metricsByCircuitName)), transpose(baseBenchmark), '', 'Circuit')} +Tree insertion stats +${getTableContent(pick(benchmark, metricsByLeafCount), baseBenchmark, 'leaves')} + ### Miscellaneous Transaction sizes based on how many contracts are deployed in the tx. diff --git a/yarn-project/types/src/stats/metrics.ts b/yarn-project/types/src/stats/metrics.ts index b5b8bd4948e5..a66d31be3a16 100644 --- a/yarn-project/types/src/stats/metrics.ts +++ b/yarn-project/types/src/stats/metrics.ts @@ -6,7 +6,7 @@ export type MetricGroupBy = | 'chain-length' | 'circuit-name' | 'contract-count' - | 'tree-name' + | 'leaf-count' | 'private-writes' | 'public-writes'; @@ -147,9 +147,15 @@ export const Metrics = [ events: ['tx-sequencer-processing'], }, { - name: 'tree_insertion_time_in_ms', - groupBy: 'tree-name', - description: 'Time to insert a batch of leaves into a tree', + name: 'batch_insert_into_append_only_tree_ms', + groupBy: 'leaf-count', + description: 'Time to insert a batch of leaves into an append-only tree', + events: ['tree-insertion'], + }, + { + name: 'batch_insert_into_indexed_tree_ms', + groupBy: 'leaf-count', + description: 'Time to insert a batch of leaves into an indexed tree', events: ['tree-insertion'], }, ] as const satisfies readonly Metric[]; From e1e86822020c3ffa294301b6332342c56904553d Mon Sep 17 00:00:00 2001 From: Alex Gherghisan Date: Mon, 8 Jan 2024 12:15:40 +0000 Subject: [PATCH 4/7] feat: log tx processing time --- yarn-project/scripts/src/benchmarks/markdown.ts | 7 +++++++ .../sequencer-client/src/sequencer/public_processor.ts | 3 ++- yarn-project/types/src/stats/metrics.ts | 7 +++---- 3 files changed, 12 insertions(+), 5 deletions(-) diff --git a/yarn-project/scripts/src/benchmarks/markdown.ts b/yarn-project/scripts/src/benchmarks/markdown.ts index fa4c340dffed..c98f6d05fcaf 100644 --- a/yarn-project/scripts/src/benchmarks/markdown.ts +++ b/yarn-project/scripts/src/benchmarks/markdown.ts @@ -182,6 +182,9 @@ export function getMarkdown() { const metricsByContractCount = Metrics.filter(m => m.groupBy === 'contract-count').map(m => m.name); const metricsByLeafCount = Metrics.filter(m => m.groupBy === 'leaf-count').map(m => m.name); + const metricsTxPxeProcessing = Metrics.filter(m => m.name === 'tx_pxe_processing_time_ms').map(m => m.name); + const metricsTxSeqProcessing = Metrics.filter(m => m.name === 'tx_sequencer_processing_time_ms').map(m => m.name); + const baseHash = process.env.BASE_COMMIT_HASH; const baseUrl = baseHash && `[\`${baseHash.slice(0, 8)}\`](${S3_URL}/benchmarks-v1/master/${baseHash}.json)`; const baseCommitText = baseUrl @@ -230,6 +233,10 @@ ${getTableContent(pick(benchmark, metricsByLeafCount), baseBenchmark, 'leaves')} Transaction sizes based on how many contracts are deployed in the tx. ${getTableContent(pick(benchmark, metricsByContractCount), baseBenchmark, 'deployed contracts')} +Transaction processing duration by data writes. +${getTableContent(pick(benchmark, metricsTxPxeProcessing), baseBenchmark, 'new commitments')} +${getTableContent(pick(benchmark, metricsTxSeqProcessing), baseBenchmark, 'public data writes')} + ${COMMENT_MARK} `; diff --git a/yarn-project/sequencer-client/src/sequencer/public_processor.ts b/yarn-project/sequencer-client/src/sequencer/public_processor.ts index b1d8875bda0e..88b470bd8349 100644 --- a/yarn-project/sequencer-client/src/sequencer/public_processor.ts +++ b/yarn-project/sequencer-client/src/sequencer/public_processor.ts @@ -172,7 +172,8 @@ export class PublicProcessor { this.log(`Processed public part of ${tx.data.end.newNullifiers[0]}`, { eventName: 'tx-sequencer-processing', duration: timer.ms(), - publicDataUpdateRequests: processedTransaction.data.end.publicDataUpdateRequests.length ?? 0, + publicDataUpdateRequests: + processedTransaction.data.end.publicDataUpdateRequests.filter(x => !x.leafSlot.isZero()).length ?? 0, ...tx.getStats(), } satisfies TxSequencerProcessingStats); diff --git a/yarn-project/types/src/stats/metrics.ts b/yarn-project/types/src/stats/metrics.ts index a66d31be3a16..8e8c3736fda1 100644 --- a/yarn-project/types/src/stats/metrics.ts +++ b/yarn-project/types/src/stats/metrics.ts @@ -7,8 +7,7 @@ export type MetricGroupBy = | 'circuit-name' | 'contract-count' | 'leaf-count' - | 'private-writes' - | 'public-writes'; + | 'data-writes'; /** Definition of a metric to track in benchmarks. */ export interface Metric { @@ -136,13 +135,13 @@ export const Metrics = [ }, { name: 'tx_pxe_processing_time_ms', - groupBy: 'private-writes', + groupBy: 'data-writes', description: 'Time to process the private part of a tx.', events: ['tx-pxe-processing'], }, { name: 'tx_sequencer_processing_time_ms', - groupBy: 'public-writes', + groupBy: 'data-writes', description: 'Time to process the public part of a tx.', events: ['tx-sequencer-processing'], }, From 994607eed645d568e2498d01a5b82d3e6bc192d0 Mon Sep 17 00:00:00 2001 From: Alex Gherghisan Date: Mon, 8 Jan 2024 12:15:51 +0000 Subject: [PATCH 5/7] fix: metrics handle missing values --- yarn-project/scripts/src/benchmarks/markdown.ts | 15 +++++++++++---- 1 file changed, 11 insertions(+), 4 deletions(-) diff --git a/yarn-project/scripts/src/benchmarks/markdown.ts b/yarn-project/scripts/src/benchmarks/markdown.ts index c98f6d05fcaf..151b07662502 100644 --- a/yarn-project/scripts/src/benchmarks/markdown.ts +++ b/yarn-project/scripts/src/benchmarks/markdown.ts @@ -95,10 +95,13 @@ function getCell( row: string, col: string, ) { - const value = data[row][col]; + const value: number | undefined = data[row][col]; const formattedValue = formatValue(value); - const baseValue = base ? (base[row] ?? {})[col] : undefined; - const percentDiff = baseValue ? Math.round(((value - baseValue) / baseValue) * 100) : undefined; + const baseValue: number | undefined = base?.[row]?.[col]; + const percentDiff = + typeof baseValue === 'number' && typeof value === 'number' + ? Math.round(((value - baseValue) / baseValue) * 100) + : undefined; if (!percentDiff || Math.abs(percentDiff) < 1) { return formattedValue; } @@ -118,7 +121,11 @@ function withDesc(name: string) { } /** Formats a numeric value for display. */ -function formatValue(value: number) { +function formatValue(value: number | undefined): string { + if (typeof value === 'undefined') { + return 'N/A'; + } + if (value < 100) { return value.toPrecision(3); } From 230e321bb1c011bb5e7620308886473f06d00b9f Mon Sep 17 00:00:00 2001 From: Alex Gherghisan Date: Mon, 8 Jan 2024 13:28:23 +0000 Subject: [PATCH 6/7] fix: tree insertion title and description --- yarn-project/scripts/src/benchmarks/markdown.ts | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/yarn-project/scripts/src/benchmarks/markdown.ts b/yarn-project/scripts/src/benchmarks/markdown.ts index 151b07662502..4802b55f401f 100644 --- a/yarn-project/scripts/src/benchmarks/markdown.ts +++ b/yarn-project/scripts/src/benchmarks/markdown.ts @@ -232,7 +232,9 @@ ${getTableContent(pick(benchmark, metricsByChainLength), baseBenchmark, 'blocks' Stats on running time and I/O sizes collected for every circuit run across all benchmarks. ${getTableContent(transpose(pick(benchmark, metricsByCircuitName)), transpose(baseBenchmark), '', 'Circuit')} -Tree insertion stats +### Tree insertion stats + +The duration to insert a fixed batch of leaves into each tree type. ${getTableContent(pick(benchmark, metricsByLeafCount), baseBenchmark, 'leaves')} ### Miscellaneous From cb82a0bc74300da5420ebc4861e68e65f38b6013 Mon Sep 17 00:00:00 2001 From: Alex Gherghisan Date: Mon, 8 Jan 2024 19:21:25 +0000 Subject: [PATCH 7/7] fix: divide by zero --- yarn-project/scripts/src/benchmarks/markdown.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/yarn-project/scripts/src/benchmarks/markdown.ts b/yarn-project/scripts/src/benchmarks/markdown.ts index 4802b55f401f..163db3beefab 100644 --- a/yarn-project/scripts/src/benchmarks/markdown.ts +++ b/yarn-project/scripts/src/benchmarks/markdown.ts @@ -99,7 +99,7 @@ function getCell( const formattedValue = formatValue(value); const baseValue: number | undefined = base?.[row]?.[col]; const percentDiff = - typeof baseValue === 'number' && typeof value === 'number' + typeof baseValue === 'number' && baseValue > 0 && typeof value === 'number' ? Math.round(((value - baseValue) / baseValue) * 100) : undefined; if (!percentDiff || Math.abs(percentDiff) < 1) {