Skip to content

Commit

Permalink
chore: Reduce log verbosity in local e2e tests (#5622)
Browse files Browse the repository at this point in the history
Updates **all** debug logger uses to log with an explicit log level. The
log level for every single usage definitely needs finer tuning, but it's
a first step.

Defaults e2e tests run locally (not on CI) to `verbose` log level.
Removes almost-unused `trace` log level (which was below `debug`).
  • Loading branch information
spalladino authored Apr 9, 2024
1 parent 4c5579d commit c496a10
Show file tree
Hide file tree
Showing 116 changed files with 502 additions and 496 deletions.
4 changes: 2 additions & 2 deletions boxes/boxes/react/tests/node.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -16,11 +16,11 @@ describe('BoxReact Contract Tests', () => {
.send({ contractAddressSalt: salt })
.deployed();

logger(`L2 contract deployed at ${contract.address}`);
logger.info(`L2 contract deployed at ${contract.address}`);
}, 60000);

test('Can set a number', async () => {
logger(`${await wallet.getRegisteredAccounts()}`);
logger.info(`${await wallet.getRegisteredAccounts()}`);
await contract.methods.setNumber(numberToSet, wallet.getCompleteAddress()).send().wait();
}, 40000);

Expand Down
16 changes: 8 additions & 8 deletions yarn-project/archiver/src/archiver/archiver.ts
Original file line number Diff line number Diff line change
Expand Up @@ -128,7 +128,7 @@ export class Archiver implements ArchiveSource {
}

if (blockUntilSynced) {
this.log(`Performing initial chain sync...`);
this.log.info(`Performing initial chain sync...`);
await this.sync(blockUntilSynced);
}

Expand Down Expand Up @@ -197,7 +197,7 @@ export class Archiver implements ArchiveSource {
);

if (retrievedL1ToL2Messages.retrievedData.length !== 0) {
this.log(
this.log.verbose(
`Retrieved ${retrievedL1ToL2Messages.retrievedData.length} new L1 -> L2 messages between L1 blocks ${
l1SynchPoint.messagesSynchedTo + 1n
} and ${currentL1BlockNumber}.`,
Expand Down Expand Up @@ -250,7 +250,7 @@ export class Archiver implements ArchiveSource {
if (blocks.length === 0) {
return;
} else {
this.log(
this.log.verbose(
`Retrieved ${blocks.length} new L2 blocks between L1 blocks ${
l1SynchPoint.blocksSynchedTo + 1n
} and ${currentL1BlockNumber}.`,
Expand Down Expand Up @@ -296,7 +296,7 @@ export class Archiver implements ArchiveSource {
e => e.toContractClassPublic(),
);
if (contractClasses.length > 0) {
contractClasses.forEach(c => this.log(`Registering contract class ${c.id.toString()}`));
contractClasses.forEach(c => this.log.verbose(`Registering contract class ${c.id.toString()}`));
await this.store.addContractClasses(contractClasses, blockNum);
}
}
Expand All @@ -308,7 +308,7 @@ export class Archiver implements ArchiveSource {
private async storeDeployedContractInstances(allLogs: UnencryptedL2Log[], blockNum: number) {
const contractInstances = ContractInstanceDeployedEvent.fromLogs(allLogs).map(e => e.toContractInstance());
if (contractInstances.length > 0) {
contractInstances.forEach(c => this.log(`Storing contract instance at ${c.address.toString()}`));
contractInstances.forEach(c => this.log.verbose(`Storing contract instance at ${c.address.toString()}`));
await this.store.addContractInstances(contractInstances, blockNum);
}
}
Expand Down Expand Up @@ -351,7 +351,7 @@ export class Archiver implements ArchiveSource {

// Store the functions in the contract class in a single operation
if (validFnCount > 0) {
this.log(`Storing ${validFnCount} functions for contract class ${contractClassId.toString()}`);
this.log.verbose(`Storing ${validFnCount} functions for contract class ${contractClassId.toString()}`);
}
await this.store.addFunctions(contractClassId, validPrivateFns, validUnconstrainedFns);
}
Expand All @@ -362,10 +362,10 @@ export class Archiver implements ArchiveSource {
* @returns A promise signalling completion of the stop process.
*/
public async stop(): Promise<void> {
this.log('Stopping...');
this.log.debug('Stopping...');
await this.runningPromise?.stop();

this.log('Stopped.');
this.log.info('Stopped.');
return Promise.resolve();
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -186,7 +186,7 @@ export class BlockStore {
}

if (start < INITIAL_L2_BLOCK_NUM) {
this.#log(`Clamping start block ${start} to ${INITIAL_L2_BLOCK_NUM}`);
this.#log.verbose(`Clamping start block ${start} to ${INITIAL_L2_BLOCK_NUM}`);
start = INITIAL_L2_BLOCK_NUM;
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -131,7 +131,7 @@ export class LogStore {
const txLogs = unencryptedLogsInBlock.txLogs[txIndex].unrollLogs();
maxLogsHit = this.#accumulateLogs(logs, blockNumber, txIndex, txLogs, filter);
if (maxLogsHit) {
this.#log(`Max logs hit at block ${blockNumber}`);
this.#log.debug(`Max logs hit at block ${blockNumber}`);
break loopOverBlocks;
}
}
Expand Down
6 changes: 3 additions & 3 deletions yarn-project/aztec-node/src/aztec-node/server.ts
Original file line number Diff line number Diff line change
Expand Up @@ -102,7 +102,7 @@ export class AztecNodeService implements AztecNode {
`Inbox: ${config.l1Contracts.inboxAddress.toString()}\n` +
`Outbox: ${config.l1Contracts.outboxAddress.toString()}\n` +
`Availability Oracle: ${config.l1Contracts.availabilityOracleAddress.toString()}`;
this.log(message);
this.log.info(message);
}

/**
Expand Down Expand Up @@ -704,10 +704,10 @@ export class AztecNodeService implements AztecNode {

// using a snapshot could be less efficient than using the committed db
if (blockNumber === 'latest' || blockNumber === blockSyncedTo) {
this.log(`Using committed db for block ${blockNumber}, world state synced upto ${blockSyncedTo}`);
this.log.debug(`Using committed db for block ${blockNumber}, world state synced upto ${blockSyncedTo}`);
return this.worldStateSynchronizer.getCommitted();
} else if (blockNumber < blockSyncedTo) {
this.log(`Using snapshot for block ${blockNumber}, world state synced upto ${blockSyncedTo}`);
this.log.debug(`Using snapshot for block ${blockNumber}, world state synced upto ${blockSyncedTo}`);
return this.worldStateSynchronizer.getSnapshot(blockNumber);
} else {
throw new Error(`Block ${blockNumber} not yet synced`);
Expand Down
8 changes: 5 additions & 3 deletions yarn-project/aztec-node/src/aztec-node/simulator-factory.ts
Original file line number Diff line number Diff line change
Expand Up @@ -13,12 +13,14 @@ export async function getSimulationProvider(
try {
await fs.access(config.acvmBinaryPath, fs.constants.R_OK);
await fs.mkdir(config.acvmWorkingDirectory, { recursive: true });
logger?.(`Using native ACVM at ${config.acvmBinaryPath} and working directory ${config.acvmWorkingDirectory}`);
logger?.info(
`Using native ACVM at ${config.acvmBinaryPath} and working directory ${config.acvmWorkingDirectory}`,
);
return new NativeACVMSimulator(config.acvmWorkingDirectory, config.acvmBinaryPath);
} catch {
logger?.(`Failed to access ACVM at ${config.acvmBinaryPath}, falling back to WASM`);
logger?.warn(`Failed to access ACVM at ${config.acvmBinaryPath}, falling back to WASM`);
}
}
logger?.('Using WASM ACVM simulation');
logger?.info('Using WASM ACVM simulation');
return new WASMSimulator();
}
6 changes: 3 additions & 3 deletions yarn-project/aztec.js/src/contract/deploy_method.ts
Original file line number Diff line number Diff line change
Expand Up @@ -140,11 +140,11 @@ export class DeployMethod<TContract extends ContractBase = Contract> extends Bas
// Register the contract class if it hasn't been published already.
if (!options.skipClassRegistration) {
if (await this.pxe.isContractClassPubliclyRegistered(contractClass.id)) {
this.log(
this.log.debug(
`Skipping registration of already registered contract class ${contractClass.id.toString()} for ${instance.address.toString()}`,
);
} else {
this.log(
this.log.info(
`Creating request for registering contract class ${contractClass.id.toString()} as part of deployment for ${instance.address.toString()}`,
);
calls.push((await registerContractClass(this.wallet, this.artifact)).request());
Expand All @@ -170,7 +170,7 @@ export class DeployMethod<TContract extends ContractBase = Contract> extends Bas
public send(options: DeployOptions = {}): DeploySentTx<TContract> {
const txHashPromise = super.send(options).getTxHash();
const instance = this.getInstance(options);
this.log(
this.log.debug(
`Sent deployment tx of ${this.artifact.name} contract with deployment address ${instance.address.toString()}`,
);
return new DeploySentTx(this.pxe, txHashPromise, this.postDeployCtor, instance);
Expand Down
2 changes: 1 addition & 1 deletion yarn-project/aztec.js/src/contract/deploy_sent_tx.ts
Original file line number Diff line number Diff line change
Expand Up @@ -44,7 +44,7 @@ export class DeploySentTx<TContract extends Contract = Contract> extends SentTx
*/
public async deployed(opts?: DeployedWaitOpts): Promise<TContract> {
const receipt = await this.wait(opts);
this.log(`Contract ${this.instance.address.toString()} successfully deployed.`);
this.log.info(`Contract ${this.instance.address.toString()} successfully deployed.`);
return receipt.contract;
}

Expand Down
16 changes: 8 additions & 8 deletions yarn-project/aztec.js/src/utils/cheat_codes.ts
Original file line number Diff line number Diff line change
Expand Up @@ -90,7 +90,7 @@ export class EthCheatCodes {
if (res.error) {
throw new Error(`Error mining: ${res.error.message}`);
}
this.logger(`Mined ${numberOfBlocks} blocks`);
this.logger.info(`Mined ${numberOfBlocks} blocks`);
}

/**
Expand All @@ -102,7 +102,7 @@ export class EthCheatCodes {
if (res.error) {
throw new Error(`Error setting next block timestamp: ${res.error.message}`);
}
this.logger(`Set next block timestamp to ${timestamp}`);
this.logger.info(`Set next block timestamp to ${timestamp}`);
}

/**
Expand All @@ -116,7 +116,7 @@ export class EthCheatCodes {
}
const jsonContent = JSON.stringify(res.result);
fs.writeFileSync(`${fileName}.json`, jsonContent, 'utf8');
this.logger(`Dumped state to ${fileName}`);
this.logger.info(`Dumped state to ${fileName}`);
}

/**
Expand All @@ -129,7 +129,7 @@ export class EthCheatCodes {
if (res.error) {
throw new Error(`Error loading state: ${res.error.message}`);
}
this.logger(`Loaded state from ${fileName}`);
this.logger.info(`Loaded state from ${fileName}`);
}

/**
Expand All @@ -155,7 +155,7 @@ export class EthCheatCodes {
if (res.error) {
throw new Error(`Error setting storage for contract ${contract} at ${slot}: ${res.error.message}`);
}
this.logger(`Set storage for contract ${contract} at ${slot} to ${value}`);
this.logger.info(`Set storage for contract ${contract} at ${slot} to ${value}`);
}

/**
Expand All @@ -179,7 +179,7 @@ export class EthCheatCodes {
if (res.error) {
throw new Error(`Error impersonating ${who}: ${res.error.message}`);
}
this.logger(`Impersonating ${who}`);
this.logger.info(`Impersonating ${who}`);
}

/**
Expand All @@ -191,7 +191,7 @@ export class EthCheatCodes {
if (res.error) {
throw new Error(`Error when stopping the impersonation of ${who}: ${res.error.message}`);
}
this.logger(`Stopped impersonating ${who}`);
this.logger.info(`Stopped impersonating ${who}`);
}

/**
Expand All @@ -204,7 +204,7 @@ export class EthCheatCodes {
if (res.error) {
throw new Error(`Error setting bytecode for ${contract}: ${res.error.message}`);
}
this.logger(`Set bytecode for ${contract} to ${bytecode}`);
this.logger.info(`Set bytecode for ${contract} to ${bytecode}`);
}

/**
Expand Down
4 changes: 2 additions & 2 deletions yarn-project/aztec.js/src/utils/pxe.ts
Original file line number Diff line number Diff line change
Expand Up @@ -5,11 +5,11 @@ import { retryUntil } from '@aztec/foundation/retry';
export const waitForPXE = async (pxe: PXE, logger?: DebugLogger) => {
await retryUntil(async () => {
try {
logger?.('Attempting to contact PXE...');
logger?.debug('Attempting to contact PXE...');
await pxe.getNodeInfo();
return true;
} catch (error) {
logger?.('Failed to contact PXE!');
logger?.verbose('Failed to contact PXE');
}
return undefined;
}, 'RPC Get Node Info');
Expand Down
4 changes: 2 additions & 2 deletions yarn-project/aztec/src/bin/index.ts
Original file line number Diff line number Diff line change
Expand Up @@ -62,7 +62,7 @@ async function main() {
}

main().catch(err => {
debugLogger(`Error in command execution`);
debugLogger(err);
debugLogger.error(`Error in command execution`);
debugLogger.error(err);
process.exit(1);
});
2 changes: 1 addition & 1 deletion yarn-project/aztec/src/cli/cli.ts
Original file line number Diff line number Diff line change
Expand Up @@ -69,7 +69,7 @@ export function getProgram(userLog: LogFn, debugLogger: DebugLogger): Command {
httpServer.listen(options.port);
userLog(`Aztec Server listening on port ${options.port}`);
}
installSignalHandlers(debugLogger, signalHandlers);
installSignalHandlers(debugLogger.info, signalHandlers);
});
return program;
}
22 changes: 11 additions & 11 deletions yarn-project/aztec/src/examples/token.ts
Original file line number Diff line number Diff line change
Expand Up @@ -30,25 +30,25 @@ const TRANSFER_AMOUNT = 33n;
* Main function.
*/
async function main() {
logger('Running token contract test on HTTP interface.');
logger.info('Running token contract test on HTTP interface.');

aliceWallet = await getSingleKeyAccount(pxe, alicePrivateKey).waitSetup();
bobWallet = await getSingleKeyAccount(pxe, bobPrivateKey).waitSetup();
const alice = aliceWallet.getCompleteAddress();
const bob = bobWallet.getCompleteAddress();

logger(`Created Alice and Bob accounts: ${alice.address.toString()}, ${bob.address.toString()}`);
logger.info(`Created Alice and Bob accounts: ${alice.address.toString()}, ${bob.address.toString()}`);

logger('Deploying Token...');
logger.info('Deploying Token...');
const token = await TokenContract.deploy(aliceWallet, alice, 'TokenName', 'TokenSymbol', 18).send().deployed();
logger('Token deployed');
logger.info('Token deployed');

// Create the contract abstraction and link it to Alice's and Bob's wallet for future signing
const tokenAlice = await TokenContract.at(token.address, aliceWallet);
const tokenBob = await TokenContract.at(token.address, bobWallet);

// Mint tokens to Alice
logger(`Minting ${ALICE_MINT_BALANCE} more coins to Alice...`);
logger.info(`Minting ${ALICE_MINT_BALANCE} more coins to Alice...`);

// Create a secret and a corresponding hash that will be used to mint funds privately
const aliceSecret = Fr.random();
Expand All @@ -73,26 +73,26 @@ async function main() {
// Make the tokens spendable by redeeming them using the secret (converts the "pending shield note" created above
// to a "token note")
await tokenAlice.methods.redeem_shield(alice, ALICE_MINT_BALANCE, aliceSecret).send().wait();
logger(`${ALICE_MINT_BALANCE} tokens were successfully minted and redeemed by Alice`);
logger.info(`${ALICE_MINT_BALANCE} tokens were successfully minted and redeemed by Alice`);

const balanceAfterMint = await tokenAlice.methods.balance_of_private(alice).simulate();
logger(`Tokens successfully minted. New Alice's balance: ${balanceAfterMint}`);
logger.info(`Tokens successfully minted. New Alice's balance: ${balanceAfterMint}`);

// We will now transfer tokens from Alice to Bob
logger(`Transferring ${TRANSFER_AMOUNT} tokens from Alice to Bob...`);
logger.info(`Transferring ${TRANSFER_AMOUNT} tokens from Alice to Bob...`);
await tokenAlice.methods.transfer(alice, bob, TRANSFER_AMOUNT, 0).send().wait();

// Check the new balances
const aliceBalance = await tokenAlice.methods.balance_of_private(alice).simulate();
logger(`Alice's balance ${aliceBalance}`);
logger.info(`Alice's balance ${aliceBalance}`);

const bobBalance = await tokenBob.methods.balance_of_private(bob).simulate();
logger(`Bob's balance ${bobBalance}`);
logger.info(`Bob's balance ${bobBalance}`);
}

main()
.then(() => {
logger('Finished running successfully.');
logger.info('Finished running successfully.');
process.exit(0);
})
.catch(err => {
Expand Down
4 changes: 2 additions & 2 deletions yarn-project/aztec/src/sandbox.ts
Original file line number Diff line number Diff line change
Expand Up @@ -156,7 +156,7 @@ async function initL1GasPortal(
{} as any,
);

logger(
logger.info(
`Initialized Gas Portal at ${l1ContractAddresses.gasPortalAddress} to bridge between L1 ${l1ContractAddresses.gasTokenAddress} to L2 ${l2GasTokenAddress}`,
);
}
Expand All @@ -179,7 +179,7 @@ async function deployCanonicalL2GasToken(deployer: Wallet, l1ContractAddresses:

await batch.send().wait();

logger(`Deployed Gas Token on L2 at ${canonicalGasToken.address}`);
logger.info(`Deployed Gas Token on L2 at ${canonicalGasToken.address}`);
}

/** Sandbox settings. */
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,7 @@ import { createDebugLogger } from '@aztec/foundation/log';
import { GrumpkinScalar, type Point } from '../../../index.js';
import { Grumpkin } from './index.js';

const debug = createDebugLogger('bb:grumpkin_test');
const log = createDebugLogger('bb:grumpkin_test');

describe('grumpkin', () => {
let grumpkin!: Grumpkin;
Expand All @@ -24,13 +24,13 @@ describe('grumpkin', () => {

const start = new Date().getTime();
const outputPoints = grumpkin.batchMul(inputPoints, exponent);
debug(`batch mul in: ${new Date().getTime() - start}ms`);
log.debug(`batch mul in: ${new Date().getTime() - start}ms`);

const start2 = new Date().getTime();
for (let i = 0; i < numPoints; ++i) {
grumpkin.mul(inputPoints[i], exponent);
}
debug(`regular mul in: ${new Date().getTime() - start2}ms`);
log.debug(`regular mul in: ${new Date().getTime() - start2}ms`);

for (let i = 0; i < numPoints; ++i) {
const lhs = outputPoints[i];
Expand Down
2 changes: 1 addition & 1 deletion yarn-project/circuits.js/src/contract/artifact_hash.ts
Original file line number Diff line number Diff line change
Expand Up @@ -47,7 +47,7 @@ export function computeArtifactHash(

const preimage = computeArtifactHashPreimage(artifact);
const artifactHash = computeArtifactHash(computeArtifactHashPreimage(artifact));
getLogger().trace('Computed artifact hash', { artifactHash, ...preimage });
getLogger().debug('Computed artifact hash', { artifactHash, ...preimage });
return artifactHash;
}

Expand Down
Loading

0 comments on commit c496a10

Please sign in to comment.