From e83726dddbc7ea98c86b99a7439e39f076a63b25 Mon Sep 17 00:00:00 2001
From: just-mitch <68168980+just-mitch@users.noreply.github.com>
Date: Wed, 27 Nov 2024 09:36:59 -0500
Subject: [PATCH] chore: add traces and histograms to avm simulator (#10233)
Add a histogram for tracking the gas/second of avm enqueued call
simulations.
Assert that we are above 2.5 Mgas/second in the public transfer test.
Also some traces at the enqueued call level.
See graph attached. Interestingly, `transfer_in_public` sits constantly
around 5.5 Mgas/s, but `total_supply` was the worst at around 3 Mgas/s.
fix #10145
fix #10146
---
.../end-to-end/scripts/e2e_test_config.yml | 3 ++-
.../e2e_token_contract/token_contract_test.ts | 6 +++--
.../transfer_in_public.test.ts | 19 +++++++++++++++
.../src/fixtures/snapshot_manager.ts | 2 +-
.../simulator/src/public/executor_metrics.ts | 24 ++++++++++++++++++-
.../simulator/src/public/public_processor.ts | 3 +++
.../src/public/public_tx_simulator.ts | 23 ++++++++++++++----
.../telemetry-client/src/attributes.ts | 5 ++++
yarn-project/telemetry-client/src/metrics.ts | 1 +
yarn-project/telemetry-client/src/otel.ts | 11 ++++++++-
10 files changed, 87 insertions(+), 10 deletions(-)
diff --git a/yarn-project/end-to-end/scripts/e2e_test_config.yml b/yarn-project/end-to-end/scripts/e2e_test_config.yml
index 4faa61cceb7..a09f5f5a568 100644
--- a/yarn-project/end-to-end/scripts/e2e_test_config.yml
+++ b/yarn-project/end-to-end/scripts/e2e_test_config.yml
@@ -84,7 +84,8 @@ tests:
e2e_state_vars: {}
e2e_static_calls: {}
e2e_synching: {}
- e2e_token_contract: {}
+ e2e_token_contract:
+ with_alerts: true
e2e_p2p_gossip:
test_path: 'e2e_p2p/gossip_network.test.ts'
with_alerts: true
diff --git a/yarn-project/end-to-end/src/e2e_token_contract/token_contract_test.ts b/yarn-project/end-to-end/src/e2e_token_contract/token_contract_test.ts
index 711e3fa92d7..0eb7afb8b83 100644
--- a/yarn-project/end-to-end/src/e2e_token_contract/token_contract_test.ts
+++ b/yarn-project/end-to-end/src/e2e_token_contract/token_contract_test.ts
@@ -14,7 +14,7 @@ import {
import { mintTokensToPrivate } from '../fixtures/token_utils.js';
import { TokenSimulator } from '../simulators/token_simulator.js';
-const { E2E_DATA_PATH: dataPath } = process.env;
+const { E2E_DATA_PATH: dataPath, METRICS_PORT: metricsPort } = process.env;
export class TokenContractTest {
static TOKEN_NAME = 'USDC';
@@ -30,7 +30,9 @@ export class TokenContractTest {
constructor(testName: string) {
this.logger = createDebugLogger(`aztec:e2e_token_contract:${testName}`);
- this.snapshotManager = createSnapshotManager(`e2e_token_contract/${testName}`, dataPath);
+ this.snapshotManager = createSnapshotManager(`e2e_token_contract/${testName}`, dataPath, {
+ metricsPort: metricsPort ? parseInt(metricsPort) : undefined,
+ });
}
/**
diff --git a/yarn-project/end-to-end/src/e2e_token_contract/transfer_in_public.test.ts b/yarn-project/end-to-end/src/e2e_token_contract/transfer_in_public.test.ts
index 0c92a459ad0..b0440880ecb 100644
--- a/yarn-project/end-to-end/src/e2e_token_contract/transfer_in_public.test.ts
+++ b/yarn-project/end-to-end/src/e2e_token_contract/transfer_in_public.test.ts
@@ -1,8 +1,23 @@
import { Fr } from '@aztec/aztec.js';
import { U128_UNDERFLOW_ERROR } from '../fixtures/fixtures.js';
+import { AlertChecker, type AlertConfig } from '../quality_of_service/alert_checker.js';
import { TokenContractTest } from './token_contract_test.js';
+const CHECK_ALERTS = process.env.CHECK_ALERTS === 'true';
+
+const qosAlerts: AlertConfig[] = [
+ {
+ // Dummy alert to check that the metric is being emitted.
+ // Separate benchmark tests will use dedicated machines with the published system requirements.
+ alert: 'publishing_mana_per_second',
+ expr: 'rate(aztec_public_executor_simulation_mana_per_second_per_second_sum[5m]) / rate(aztec_public_executor_simulation_mana_per_second_per_second_count[5m]) < 10',
+ for: '5m',
+ annotations: {},
+ labels: {},
+ },
+];
+
describe('e2e_token_contract transfer public', () => {
const t = new TokenContractTest('transfer_in_public');
let { asset, accounts, tokenSim, wallets, badAccount } = t;
@@ -17,6 +32,10 @@ describe('e2e_token_contract transfer public', () => {
afterAll(async () => {
await t.teardown();
+ if (CHECK_ALERTS) {
+ const alertChecker = new AlertChecker(t.logger);
+ await alertChecker.runAlertCheck(qosAlerts);
+ }
});
afterEach(async () => {
diff --git a/yarn-project/end-to-end/src/fixtures/snapshot_manager.ts b/yarn-project/end-to-end/src/fixtures/snapshot_manager.ts
index 6f58a48dda6..488e7291bda 100644
--- a/yarn-project/end-to-end/src/fixtures/snapshot_manager.ts
+++ b/yarn-project/end-to-end/src/fixtures/snapshot_manager.ts
@@ -345,7 +345,7 @@ async function setupFromFresh(
aztecNodeConfig.bbWorkingDirectory = bbConfig.bbWorkingDirectory;
}
- const telemetry = await getEndToEndTestTelemetryClient(opts.metricsPort, /*serviceName*/ 'basenode');
+ const telemetry = await getEndToEndTestTelemetryClient(opts.metricsPort, /*serviceName*/ statePath);
logger.verbose('Creating and synching an aztec node...');
const aztecNode = await AztecNodeService.createAndSync(aztecNodeConfig, { telemetry });
diff --git a/yarn-project/simulator/src/public/executor_metrics.ts b/yarn-project/simulator/src/public/executor_metrics.ts
index 4b648dfe4ef..17267f58b90 100644
--- a/yarn-project/simulator/src/public/executor_metrics.ts
+++ b/yarn-project/simulator/src/public/executor_metrics.ts
@@ -3,15 +3,20 @@ import {
type Histogram,
Metrics,
type TelemetryClient,
+ type Tracer,
type UpDownCounter,
ValueType,
+ linearBuckets,
} from '@aztec/telemetry-client';
export class ExecutorMetrics {
+ public readonly tracer: Tracer;
private fnCount: UpDownCounter;
private fnDuration: Histogram;
+ private manaPerSecond: Histogram;
constructor(client: TelemetryClient, name = 'PublicExecutor') {
+ this.tracer = client.getTracer(name);
const meter = client.getMeter(name);
this.fnCount = meter.createUpDownCounter(Metrics.PUBLIC_EXECUTOR_SIMULATION_COUNT, {
@@ -23,13 +28,30 @@ export class ExecutorMetrics {
unit: 'ms',
valueType: ValueType.INT,
});
+
+ this.manaPerSecond = meter.createHistogram(Metrics.PUBLIC_EXECUTOR_SIMULATION_MANA_PER_SECOND, {
+ description: 'Mana used per second',
+ unit: 'mana/s',
+ valueType: ValueType.INT,
+ advice: {
+ explicitBucketBoundaries: linearBuckets(0, 10_000_000, 10),
+ },
+ });
}
- recordFunctionSimulation(durationMs: number) {
+ recordFunctionSimulation(durationMs: number, manaUsed: number, fnName: string) {
this.fnCount.add(1, {
[Attributes.OK]: true,
+ [Attributes.APP_CIRCUIT_NAME]: fnName,
+ [Attributes.MANA_USED]: manaUsed,
});
this.fnDuration.record(Math.ceil(durationMs));
+ if (durationMs > 0 && manaUsed > 0) {
+ const manaPerSecond = Math.round((manaUsed * 1000) / durationMs);
+ this.manaPerSecond.record(manaPerSecond, {
+ [Attributes.APP_CIRCUIT_NAME]: fnName,
+ });
+ }
}
recordFunctionSimulationFailure() {
diff --git a/yarn-project/simulator/src/public/public_processor.ts b/yarn-project/simulator/src/public/public_processor.ts
index f19c5d06973..23e33b9ee2f 100644
--- a/yarn-project/simulator/src/public/public_processor.ts
+++ b/yarn-project/simulator/src/public/public_processor.ts
@@ -229,6 +229,9 @@ export class PublicProcessor {
return new PublicDataWrite(leafSlot, updatedBalance);
}
+ @trackSpan('PublicProcessor.processPrivateOnlyTx', (tx: Tx) => ({
+ [Attributes.TX_HASH]: tx.getTxHash().toString(),
+ }))
private async processPrivateOnlyTx(tx: Tx): Promise<[ProcessedTx]> {
const gasFees = this.globalVariables.gasFees;
const transactionFee = tx.data.gasUsed.computeFee(gasFees);
diff --git a/yarn-project/simulator/src/public/public_tx_simulator.ts b/yarn-project/simulator/src/public/public_tx_simulator.ts
index 44801eff13f..37bf5245c42 100644
--- a/yarn-project/simulator/src/public/public_tx_simulator.ts
+++ b/yarn-project/simulator/src/public/public_tx_simulator.ts
@@ -20,7 +20,7 @@ import {
} from '@aztec/circuits.js';
import { type DebugLogger, createDebugLogger } from '@aztec/foundation/log';
import { Timer } from '@aztec/foundation/timer';
-import { type TelemetryClient } from '@aztec/telemetry-client';
+import { Attributes, type TelemetryClient, type Tracer, trackSpan } from '@aztec/telemetry-client';
import { type AvmFinalizedCallResult } from '../avm/avm_contract_call_result.js';
import { type AvmPersistableStateManager, AvmSimulator } from '../avm/index.js';
@@ -55,15 +55,18 @@ export class PublicTxSimulator {
constructor(
private db: MerkleTreeReadOperations,
private worldStateDB: WorldStateDB,
- client: TelemetryClient,
+ telemetryClient: TelemetryClient,
private globalVariables: GlobalVariables,
private realAvmProvingRequests: boolean = true,
private doMerkleOperations: boolean = false,
) {
this.log = createDebugLogger(`aztec:public_tx_simulator`);
- this.metrics = new ExecutorMetrics(client, 'PublicTxSimulator');
+ this.metrics = new ExecutorMetrics(telemetryClient, 'PublicTxSimulator');
}
+ get tracer(): Tracer {
+ return this.metrics.tracer;
+ }
/**
* Simulate a transaction's public portion including all of its phases.
* @param tx - The transaction to simulate.
@@ -244,6 +247,12 @@ export class PublicTxSimulator {
* @param executionRequest - The execution request (includes args)
* @returns The result of execution.
*/
+ @trackSpan('PublicTxSimulator.simulateEnqueuedCall', (phase, context, _callRequest, executionRequest) => ({
+ [Attributes.TX_HASH]: context.getTxHash().toString(),
+ [Attributes.TARGET_ADDRESS]: executionRequest.callContext.contractAddress.toString(),
+ [Attributes.SENDER_ADDRESS]: executionRequest.callContext.msgSender.toString(),
+ [Attributes.SIMULATOR_PHASE]: TxExecutionPhase[phase].toString(),
+ }))
private async simulateEnqueuedCall(
phase: TxExecutionPhase,
context: PublicTxContext,
@@ -312,6 +321,12 @@ export class PublicTxSimulator {
* @param fnName - The name of the function
* @returns The result of execution.
*/
+ @trackSpan(
+ 'PublicTxSimulator.simulateEnqueuedCallInternal',
+ (_stateManager, _executionRequest, _allocatedGas, _transactionFee, fnName) => ({
+ [Attributes.APP_CIRCUIT_NAME]: fnName,
+ }),
+ )
private async simulateEnqueuedCallInternal(
stateManager: AvmPersistableStateManager,
executionRequest: PublicExecutionRequest,
@@ -356,7 +371,7 @@ export class PublicTxSimulator {
if (result.reverted) {
this.metrics.recordFunctionSimulationFailure();
} else {
- this.metrics.recordFunctionSimulation(timer.ms());
+ this.metrics.recordFunctionSimulation(timer.ms(), allocatedGas.sub(result.gasLeft).l2Gas, fnName);
}
return result;
diff --git a/yarn-project/telemetry-client/src/attributes.ts b/yarn-project/telemetry-client/src/attributes.ts
index 32ce263917a..87c4be24ce0 100644
--- a/yarn-project/telemetry-client/src/attributes.ts
+++ b/yarn-project/telemetry-client/src/attributes.ts
@@ -83,3 +83,8 @@ export const P2P_ID = 'aztec.p2p.id';
export const POOL_NAME = 'aztec.pool.name';
export const SEQUENCER_STATE = 'aztec.sequencer.state';
+
+export const SIMULATOR_PHASE = 'aztec.simulator.phase';
+export const TARGET_ADDRESS = 'aztec.address.target';
+export const SENDER_ADDRESS = 'aztec.address.sender';
+export const MANA_USED = 'aztec.mana.used';
diff --git a/yarn-project/telemetry-client/src/metrics.ts b/yarn-project/telemetry-client/src/metrics.ts
index f61e5be54ea..01f3e483497 100644
--- a/yarn-project/telemetry-client/src/metrics.ts
+++ b/yarn-project/telemetry-client/src/metrics.ts
@@ -71,6 +71,7 @@ export const PUBLIC_PROCESSOR_DEPLOY_BYTECODE_SIZE = 'aztec.public_processor.dep
export const PUBLIC_EXECUTOR_SIMULATION_COUNT = 'aztec.public_executor.simulation_count';
export const PUBLIC_EXECUTOR_SIMULATION_DURATION = 'aztec.public_executor.simulation_duration';
+export const PUBLIC_EXECUTOR_SIMULATION_MANA_PER_SECOND = 'aztec.public_executor.simulation_mana_per_second';
export const PUBLIC_EXECUTION_SIMULATION_BYTECODE_SIZE = 'aztec.public_executor.simulation_bytecode_size';
export const PROVING_ORCHESTRATOR_BASE_ROLLUP_INPUTS_DURATION =
diff --git a/yarn-project/telemetry-client/src/otel.ts b/yarn-project/telemetry-client/src/otel.ts
index 446c50f0e89..f94d054cb31 100644
--- a/yarn-project/telemetry-client/src/otel.ts
+++ b/yarn-project/telemetry-client/src/otel.ts
@@ -75,7 +75,16 @@ export class OpenTelemetryClient implements TelemetryClient {
}
public async stop() {
- await Promise.all([this.meterProvider.shutdown(), this.loggerProvider.shutdown()]);
+ const flushAndShutdown = async (provider: { forceFlush: () => Promise; shutdown: () => Promise }) => {
+ await provider.forceFlush();
+ await provider.shutdown();
+ };
+
+ await Promise.all([
+ flushAndShutdown(this.meterProvider),
+ flushAndShutdown(this.loggerProvider),
+ this.traceProvider instanceof NodeTracerProvider ? flushAndShutdown(this.traceProvider) : Promise.resolve(),
+ ]);
}
public static async createAndStart(config: TelemetryClientConfig, log: DebugLogger): Promise {