Skip to content

Commit

Permalink
chore: More logs cleanup (#10630)
Browse files Browse the repository at this point in the history
Cleanup of logs across archiver, sequencer, and pxe.
  • Loading branch information
spalladino authored Dec 11, 2024
1 parent eb472ff commit 00c629c
Show file tree
Hide file tree
Showing 27 changed files with 282 additions and 147 deletions.
2 changes: 2 additions & 0 deletions yarn-project/archiver/src/archiver/archiver.ts
Original file line number Diff line number Diff line change
Expand Up @@ -491,6 +491,8 @@ export class Archiver implements ArchiveSource {
this.log.info(`Downloaded L2 block ${block.data.number}`, {
blockHash: block.data.hash(),
blockNumber: block.data.number,
txCount: block.data.body.txEffects.length,
globalVariables: block.data.header.globalVariables.toInspect(),
});
}
} while (searchEndBlock < currentL1BlockNumber);
Expand Down
25 changes: 12 additions & 13 deletions yarn-project/aztec-node/src/aztec-node/server.ts
Original file line number Diff line number Diff line change
Expand Up @@ -110,13 +110,7 @@ export class AztecNodeService implements AztecNode {
this.packageVersion = getPackageInfo().version;
this.metrics = new NodeMetrics(telemetry, 'AztecNodeService');

const message =
`Started Aztec Node against chain 0x${l1ChainId.toString(16)} with contracts - \n` +
`Rollup: ${config.l1Contracts.rollupAddress.toString()}\n` +
`Registry: ${config.l1Contracts.registryAddress.toString()}\n` +
`Inbox: ${config.l1Contracts.inboxAddress.toString()}\n` +
`Outbox: ${config.l1Contracts.outboxAddress.toString()}`;
this.log.info(message);
this.log.info(`Aztec Node started on chain 0x${l1ChainId.toString(16)}`, config.l1Contracts);
}

public addEpochProofQuote(quote: EpochProofQuote): Promise<void> {
Expand Down Expand Up @@ -163,7 +157,9 @@ export class AztecNodeService implements AztecNode {
// now create the merkle trees and the world state synchronizer
const worldStateSynchronizer = await createWorldStateSynchronizer(config, archiver, telemetry);
const proofVerifier = config.realProofs ? await BBCircuitVerifier.new(config) : new TestCircuitVerifier();
log.info(`Aztec node accepting ${config.realProofs ? 'real' : 'test'} proofs`);
if (!config.realProofs) {
log.warn(`Aztec node is accepting fake proofs`);
}

// create the tx pool and the p2p client, which will need the l2 block source
const p2pClient = await createP2PClient(config, archiver, proofVerifier, worldStateSynchronizer, telemetry);
Expand Down Expand Up @@ -784,7 +780,7 @@ export class AztecNodeService implements AztecNode {
* @param tx - The transaction to simulate.
**/
public async simulatePublicCalls(tx: Tx): Promise<PublicSimulationOutput> {
this.log.info(`Simulating tx ${tx.getTxHash()}`);
const txHash = tx.getTxHash();
const blockNumber = (await this.blockSource.getBlockNumber()) + 1;

// If sequencer is not initialized, we just set these values to zero for simulation.
Expand All @@ -798,23 +794,26 @@ export class AztecNodeService implements AztecNode {
);
const prevHeader = (await this.blockSource.getBlock(-1))?.header;
const publicProcessorFactory = new PublicProcessorFactory(this.contractDataSource, this.telemetry);

const fork = await this.worldStateSynchronizer.fork();

this.log.verbose(`Simulating public calls for tx ${tx.getTxHash()}`, {
globalVariables: newGlobalVariables.toInspect(),
txHash,
blockNumber,
});

try {
const processor = publicProcessorFactory.create(fork, prevHeader, newGlobalVariables);

// REFACTOR: Consider merging ProcessReturnValues into ProcessedTx
const [processedTxs, failedTxs, returns] = await processor.process([tx]);
// REFACTOR: Consider returning the error rather than throwing
if (failedTxs.length) {
this.log.warn(`Simulated tx ${tx.getTxHash()} fails: ${failedTxs[0].error}`);
this.log.warn(`Simulated tx ${tx.getTxHash()} fails: ${failedTxs[0].error}`, { txHash });
throw failedTxs[0].error;
}

const [processedTx] = processedTxs;
this.log.debug(`Simulated tx ${tx.getTxHash()} ${processedTx.revertReason ? 'Reverts' : 'Succeeds'}`);

return new PublicSimulationOutput(
processedTx.revertReason,
processedTx.constants,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -37,7 +37,7 @@ describe('L2BlockStream', () => {
Promise.resolve(compactArray(times(limit, i => (from + i > latest ? undefined : makeBlock(from + i))))),
);

blockStream = new TestL2BlockStream(blockSource, localData, handler, { batchSize: 10 });
blockStream = new TestL2BlockStream(blockSource, localData, handler, undefined, { batchSize: 10 });
});

const makeBlock = (number: number) => ({ number } as L2Block);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -9,12 +9,11 @@ import { type L2BlockId, type L2BlockSource, type L2Tips } from '../l2_block_sou
export class L2BlockStream {
private readonly runningPromise: RunningPromise;

private readonly log = createLogger('types:l2_block_stream');

constructor(
private l2BlockSource: Pick<L2BlockSource, 'getBlocks' | 'getBlockHeader' | 'getL2Tips'>,
private localData: L2BlockStreamLocalDataProvider,
private handler: L2BlockStreamEventHandler,
private readonly log = createLogger('types:block_stream'),
private opts: {
proven?: boolean;
pollIntervalMS?: number;
Expand Down
2 changes: 1 addition & 1 deletion yarn-project/circuit-types/src/logs/tx_l2_logs.ts
Original file line number Diff line number Diff line change
Expand Up @@ -21,7 +21,7 @@ export abstract class TxL2Logs {
abstract hash(): Buffer;

constructor(
/** * An array containing logs emitted in individual function invocations in this tx. */
/** An array containing logs emitted in individual function invocations in this tx. */
public readonly functionLogs: UnencryptedFunctionL2Logs[],
) {}

Expand Down
9 changes: 9 additions & 0 deletions yarn-project/circuit-types/src/tx/tx.ts
Original file line number Diff line number Diff line change
Expand Up @@ -179,6 +179,15 @@ export class Tx extends Gossipable {
return new TxHash(firstNullifier.toBuffer());
}

/** Returns the tx hash, or undefined if none is set. */
tryGetTxHash(): TxHash | undefined {
try {
return this.getTxHash();
} catch {
return undefined;
}
}

/** Returns stats about this tx. */
getStats(): TxStats {
return {
Expand Down
11 changes: 11 additions & 0 deletions yarn-project/circuits.js/src/structs/block_header.ts
Original file line number Diff line number Diff line change
Expand Up @@ -152,6 +152,17 @@ export class BlockHeader {
return poseidon2HashWithSeparator(this.toFields(), GeneratorIndex.BLOCK_HASH);
}

toInspect() {
return {
lastArchive: this.lastArchive.root.toString(),
contentCommitment: this.contentCommitment.toInspect(),
state: this.state.toInspect(),
globalVariables: this.globalVariables.toInspect(),
totalFees: this.totalFees.toBigInt(),
totalManaUsed: this.totalManaUsed.toBigInt(),
};
}

[inspect.custom]() {
return `Header {
lastArchive: ${inspect(this.lastArchive)},
Expand Down
9 changes: 9 additions & 0 deletions yarn-project/circuits.js/src/structs/content_commitment.ts
Original file line number Diff line number Diff line change
Expand Up @@ -52,6 +52,15 @@ export class ContentCommitment {
return serializeToBuffer(this.numTxs, this.txsEffectsHash, this.inHash, this.outHash);
}

toInspect() {
return {
numTxs: this.numTxs.toNumber(),
txsEffectsHash: bufferToHex(this.txsEffectsHash),
inHash: bufferToHex(this.inHash),
outHash: bufferToHex(this.outHash),
};
}

toFields(): Fr[] {
const serialized = [
this.numTxs,
Expand Down
4 changes: 4 additions & 0 deletions yarn-project/circuits.js/src/structs/revert_code.ts
Original file line number Diff line number Diff line change
Expand Up @@ -33,6 +33,10 @@ export class RevertCode {
static readonly TEARDOWN_REVERTED: RevertCode = new RevertCode(RevertCodeEnum.TEARDOWN_REVERTED);
static readonly BOTH_REVERTED: RevertCode = new RevertCode(RevertCodeEnum.BOTH_REVERTED);

public getCode(): RevertCodeEnum {
return this.code;
}

public equals(other: RevertCode): boolean {
return this.code === other.code;
}
Expand Down
9 changes: 9 additions & 0 deletions yarn-project/circuits.js/src/structs/state_reference.ts
Original file line number Diff line number Diff line change
Expand Up @@ -69,6 +69,15 @@ export class StateReference {
return this.l1ToL2MessageTree.isZero() && this.partial.isEmpty();
}

toInspect() {
return {
l1ToL2MessageTree: this.l1ToL2MessageTree.root.toString(),
noteHashTree: this.partial.noteHashTree.root.toString(),
nullifierTree: this.partial.nullifierTree.root.toString(),
publicDataTree: this.partial.publicDataTree.root.toString(),
};
}

[inspect.custom]() {
return `StateReference {
l1ToL2MessageTree: ${inspect(this.l1ToL2MessageTree)},
Expand Down
36 changes: 19 additions & 17 deletions yarn-project/ethereum/src/deploy_l1_contracts.ts
Original file line number Diff line number Diff line change
Expand Up @@ -304,7 +304,7 @@ export const deployL1Contracts = async (
if (res.error) {
throw new Error(`Error setting block interval: ${res.error.message}`);
}
logger.info(`Set block interval to ${args.ethereumSlotDuration}`);
logger.warn(`Set block interval to ${args.ethereumSlotDuration}`);
}

logger.verbose(`Deploying contracts from ${account.address.toString()}`);
Expand All @@ -315,21 +315,21 @@ export const deployL1Contracts = async (
const govDeployer = new L1Deployer(walletClient, publicClient, args.salt, logger);

const registryAddress = await govDeployer.deploy(l1Artifacts.registry, [account.address.toString()]);
logger.info(`Deployed Registry at ${registryAddress}`);
logger.verbose(`Deployed Registry at ${registryAddress}`);

const feeAssetAddress = await govDeployer.deploy(l1Artifacts.feeAsset, [
'FeeJuice',
'FEE',
account.address.toString(),
]);
logger.info(`Deployed Fee Juice at ${feeAssetAddress}`);
logger.verbose(`Deployed Fee Juice at ${feeAssetAddress}`);

const stakingAssetAddress = await govDeployer.deploy(l1Artifacts.stakingAsset, [
'Staking',
'STK',
account.address.toString(),
]);
logger.info(`Deployed Staking Asset at ${stakingAssetAddress}`);
logger.verbose(`Deployed Staking Asset at ${stakingAssetAddress}`);

// @todo #8084
// @note These numbers are just chosen to make testing simple.
Expand All @@ -340,29 +340,29 @@ export const deployL1Contracts = async (
quorumSize,
roundSize,
]);
logger.info(`Deployed GovernanceProposer at ${governanceProposerAddress}`);
logger.verbose(`Deployed GovernanceProposer at ${governanceProposerAddress}`);

// @note @LHerskind the assets are expected to be the same at some point, but for better
// configurability they are different for now.
const governanceAddress = await govDeployer.deploy(l1Artifacts.governance, [
feeAssetAddress.toString(),
governanceProposerAddress.toString(),
]);
logger.info(`Deployed Governance at ${governanceAddress}`);
logger.verbose(`Deployed Governance at ${governanceAddress}`);

const coinIssuerAddress = await govDeployer.deploy(l1Artifacts.coinIssuer, [
feeAssetAddress.toString(),
1n * 10n ** 18n, // @todo #8084
governanceAddress.toString(),
]);
logger.info(`Deployed CoinIssuer at ${coinIssuerAddress}`);
logger.verbose(`Deployed CoinIssuer at ${coinIssuerAddress}`);

const rewardDistributorAddress = await govDeployer.deploy(l1Artifacts.rewardDistributor, [
feeAssetAddress.toString(),
registryAddress.toString(),
governanceAddress.toString(),
]);
logger.info(`Deployed RewardDistributor at ${rewardDistributorAddress}`);
logger.verbose(`Deployed RewardDistributor at ${rewardDistributorAddress}`);

logger.verbose(`Waiting for governance contracts to be deployed`);
await govDeployer.waitForDeployments();
Expand All @@ -375,7 +375,7 @@ export const deployL1Contracts = async (
feeAssetAddress.toString(),
args.l2FeeJuiceAddress.toString(),
]);
logger.info(`Deployed Fee Juice Portal at ${feeJuicePortalAddress}`);
logger.verbose(`Deployed Fee Juice Portal at ${feeJuicePortalAddress}`);

const rollupConfigArgs = {
aztecSlotDuration: args.aztecSlotDuration,
Expand All @@ -394,10 +394,10 @@ export const deployL1Contracts = async (
rollupConfigArgs,
];
const rollupAddress = await deployer.deploy(l1Artifacts.rollup, rollupArgs);
logger.info(`Deployed Rollup at ${rollupAddress}`, rollupConfigArgs);
logger.verbose(`Deployed Rollup at ${rollupAddress}`, rollupConfigArgs);

await deployer.waitForDeployments();
logger.info(`All core contracts deployed`);
logger.verbose(`All core contracts have been deployed`);

const feeJuicePortal = getContract({
address: feeJuicePortalAddress.toString(),
Expand Down Expand Up @@ -428,7 +428,7 @@ export const deployL1Contracts = async (

{
const txHash = await feeAsset.write.setFreeForAll([true], {} as any);
logger.info(`Fee asset set to free for all in ${txHash}`);
logger.verbose(`Fee asset set to free for all in ${txHash}`);
txHashes.push(txHash);
}

Expand Down Expand Up @@ -464,7 +464,7 @@ export const deployL1Contracts = async (
// @note This is used to ensure we fully wait for the transaction when running against a real chain
// otherwise we execute subsequent transactions too soon
await publicClient.waitForTransactionReceipt({ hash: mintTxHash });
logger.info(`Funding fee juice portal contract with fee juice in ${mintTxHash}`);
logger.verbose(`Funding fee juice portal contract with fee juice in ${mintTxHash}`);

if (!(await feeJuicePortal.read.initialized([]))) {
const initPortalTxHash = await feeJuicePortal.write.initialize([]);
Expand All @@ -474,7 +474,7 @@ export const deployL1Contracts = async (
logger.verbose(`Fee juice portal is already initialized`);
}

logger.info(
logger.verbose(
`Initialized Fee Juice Portal at ${feeJuicePortalAddress} to bridge between L1 ${feeAssetAddress} to L2 ${args.l2FeeJuiceAddress}`,
);

Expand Down Expand Up @@ -504,15 +504,15 @@ export const deployL1Contracts = async (
// Set initial blocks as proven if requested
if (args.assumeProvenThrough && args.assumeProvenThrough > 0) {
await rollup.write.setAssumeProvenThroughBlockNumber([BigInt(args.assumeProvenThrough)], { account });
logger.warn(`Set Rollup assumedProvenUntil to ${args.assumeProvenThrough}`);
logger.warn(`Rollup set to assumedProvenUntil to ${args.assumeProvenThrough}`);
}

// Inbox and Outbox are immutable and are deployed from Rollup's constructor so we just fetch them from the contract.
const inboxAddress = EthAddress.fromString((await rollup.read.INBOX([])) as any);
logger.info(`Inbox available at ${inboxAddress}`);
logger.verbose(`Inbox available at ${inboxAddress}`);

const outboxAddress = EthAddress.fromString((await rollup.read.OUTBOX([])) as any);
logger.info(`Outbox available at ${outboxAddress}`);
logger.verbose(`Outbox available at ${outboxAddress}`);

// We need to call a function on the registry to set the various contract addresses.
const registryContract = getContract({
Expand Down Expand Up @@ -562,6 +562,8 @@ export const deployL1Contracts = async (
governanceAddress,
};

logger.info(`Aztec L1 contracts initialized`, l1Contracts);

return {
walletClient,
publicClient,
Expand Down
8 changes: 6 additions & 2 deletions yarn-project/ethereum/src/eth_cheat_codes.ts
Original file line number Diff line number Diff line change
Expand Up @@ -77,11 +77,15 @@ export class EthCheatCodes {
* @param numberOfBlocks - The number of blocks to mine
*/
public async mine(numberOfBlocks = 1): Promise<void> {
await this.doMine(numberOfBlocks);
this.logger.verbose(`Mined ${numberOfBlocks} L1 blocks`);
}

private async doMine(numberOfBlocks = 1): Promise<void> {
const res = await this.rpcCall('hardhat_mine', [numberOfBlocks]);
if (res.error) {
throw new Error(`Error mining: ${res.error.message}`);
}
this.logger.verbose(`Mined ${numberOfBlocks} L1 blocks`);
}

/**
Expand Down Expand Up @@ -188,7 +192,7 @@ export class EthCheatCodes {
if (res.error) {
throw new Error(`Error warping: ${res.error.message}`);
}
await this.mine();
await this.doMine();
this.logger.verbose(`Warped L1 timestamp to ${timestamp}`);
}

Expand Down
4 changes: 4 additions & 0 deletions yarn-project/foundation/src/log/pino-logger.ts
Original file line number Diff line number Diff line change
Expand Up @@ -36,7 +36,10 @@ export function createLogger(module: string): Logger {
/** Log as trace. Use for when we want to denial-of-service any recipient of the logs. */
trace: (msg: string, data?: unknown) => logFn('trace', msg, data),
level: pinoLogger.level as LogLevel,
/** Whether the given level is enabled for this logger. */
isLevelEnabled: (level: LogLevel) => isLevelEnabled(pinoLogger, level),
/** Module name for the logger. */
module,
};
}

Expand Down Expand Up @@ -183,6 +186,7 @@ type ErrorLogFn = (msg: string, err?: Error | unknown, data?: LogData) => void;
export type Logger = { [K in LogLevel]: LogFn } & { /** Error log function */ error: ErrorLogFn } & {
level: LogLevel;
isLevelEnabled: (level: LogLevel) => boolean;
module: string;
};

/**
Expand Down
1 change: 1 addition & 0 deletions yarn-project/kv-store/src/interfaces/utils.ts
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,7 @@ export const mockLogger = {
trace: (msg: string, data: any) => console.log(msg, data),
level: 'trace' as const,
isLevelEnabled: (_level: string) => true,
module: 'kv-store:mock-logger',
};
/* eslint-enable no-console */

Expand Down
4 changes: 2 additions & 2 deletions yarn-project/p2p/src/client/p2p_client.ts
Original file line number Diff line number Diff line change
Expand Up @@ -221,7 +221,7 @@ export class P2PClient extends WithTracer implements P2P {

this.keepAttestationsInPoolFor = keepAttestationsInPoolFor;

this.blockStream = new L2BlockStream(l2BlockSource, this, this, {
this.blockStream = new L2BlockStream(l2BlockSource, this, this, createLogger('p2p:block_stream'), {
batchSize: blockRequestBatchSize,
pollIntervalMS: blockCheckIntervalMS,
});
Expand Down Expand Up @@ -359,7 +359,7 @@ export class P2PClient extends WithTracer implements P2P {
this.setCurrentState(P2PClientState.RUNNING);
this.syncPromise = Promise.resolve();
await this.p2pService.start();
this.log.verbose(`Block ${syncedLatestBlock} (proven ${syncedProvenBlock}) already beyond current block`);
this.log.debug(`Block ${syncedLatestBlock} (proven ${syncedProvenBlock}) already beyond current block`);
}

// publish any txs in TxPool after its doing initial sync
Expand Down
Loading

0 comments on commit 00c629c

Please sign in to comment.