Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

chore: More logs cleanup #10630

Merged
merged 2 commits into from
Dec 11, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
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();
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could this swallow a fundamental error?

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thing is tx hash computation is going to change soon, so I didn't want to mess up with the getTxHash method

} 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}`);
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just checking whether this is on L1? If so, I believe current consensus is to name that "Fee Asset".

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fun fact: "fee juice" (or feeJuice, or fee-juice, etc) appears exactly 500 times on our codebase.

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sorry, that was just across typescript. It's actually 796 times.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Will be a fun PR to try and separate fee juice from fee asset in the code.

Also I meant to comment on line 325 🤦🏼‍♂️


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
Loading