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: Tweak validator logs #10597

Merged
merged 1 commit into from
Dec 10, 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
4 changes: 3 additions & 1 deletion yarn-project/p2p/src/client/p2p_client.ts
Original file line number Diff line number Diff line change
Expand Up @@ -434,9 +434,11 @@ export class P2PClient extends WithTracer implements P2P {
public async requestTxByHash(txHash: TxHash): Promise<Tx | undefined> {
const tx = await this.p2pService.sendRequest(TX_REQ_PROTOCOL, txHash);

this.log.debug(`Requested ${txHash.toString()} from peer | success = ${!!tx}`);
if (tx) {
this.log.debug(`Received tx ${txHash.toString()} from peer`);
await this.txPool.addTxs([tx]);
} else {
this.log.debug(`Failed to receive tx ${txHash.toString()} from peer`);
}

return tx;
Expand Down
2 changes: 1 addition & 1 deletion yarn-project/p2p/src/mem_pools/tx_pool/aztec_kv_tx_pool.ts
Original file line number Diff line number Diff line change
Expand Up @@ -125,7 +125,7 @@ export class AztecKVTxPool implements TxPool {
let pendingCount = 0;
for (const [i, tx] of txs.entries()) {
const txHash = txHashes[i];
this.#log.info(`Adding tx with id ${txHash.toString()}`, {
this.#log.verbose(`Adding tx ${txHash.toString()} to pool`, {
eventName: 'tx-added-to-pool',
...tx.getStats(),
} satisfies TxAddedToPoolStats);
Expand Down
2 changes: 1 addition & 1 deletion yarn-project/p2p/src/mem_pools/tx_pool/memory_tx_pool.ts
Original file line number Diff line number Diff line change
Expand Up @@ -105,7 +105,7 @@ export class InMemoryTxPool implements TxPool {
let pending = 0;
for (const tx of txs) {
const txHash = tx.getTxHash();
this.log.debug(`Adding tx with id ${txHash.toString()}`, {
this.log.verbose(`Adding tx ${txHash.toString()} to pool`, {
eventName: 'tx-added-to-pool',
...tx.getStats(),
} satisfies TxAddedToPoolStats);
Expand Down
2 changes: 1 addition & 1 deletion yarn-project/p2p/src/service/peer_manager.ts
Original file line number Diff line number Diff line change
Expand Up @@ -221,7 +221,7 @@ export class PeerManager {
const id = peer.peerId.toString();
await this.libP2PNode.peerStore.merge(peer.peerId, { multiaddrs: [peer.multiaddrTcp] });

this.logger.debug(`Dialing peer ${id}`);
this.logger.trace(`Dialing peer ${id}`);
try {
await this.libP2PNode.dial(peer.multiaddrTcp);
} catch (error) {
Expand Down
4 changes: 2 additions & 2 deletions yarn-project/p2p/src/service/peer_scoring.ts
Original file line number Diff line number Diff line change
Expand Up @@ -82,7 +82,7 @@ export class PeerScoring {
return this.scores.get(peerId) || 0;
}

getStats(): { median: number } {
return { median: median(Array.from(this.scores.values())) ?? 0 };
getStats(): { medianScore: number } {
return { medianScore: median(Array.from(this.scores.values())) ?? 0 };
}
}
6 changes: 3 additions & 3 deletions yarn-project/p2p/src/service/reqresp/reqresp.ts
Original file line number Diff line number Diff line change
Expand Up @@ -196,7 +196,7 @@ export class ReqResp {
let stream: Stream | undefined;
try {
stream = await this.libp2p.dialProtocol(peerId, subProtocol);
this.logger.debug(`Stream opened with ${peerId.toString()} for ${subProtocol}`);
this.logger.trace(`Stream opened with ${peerId.toString()} for ${subProtocol}`);

// Open the stream with a timeout
const result = await executeTimeoutWithCustomError<Buffer>(
Expand All @@ -206,7 +206,7 @@ export class ReqResp {
);

await stream.close();
this.logger.debug(`Stream closed with ${peerId.toString()} for ${subProtocol}`);
this.logger.trace(`Stream closed with ${peerId.toString()} for ${subProtocol}`);

return result;
} catch (e: any) {
Expand All @@ -216,7 +216,7 @@ export class ReqResp {
if (stream) {
try {
await stream.close();
this.logger.debug(`Stream closed with ${peerId.toString()} for ${subProtocol}`);
this.logger.trace(`Stream closed with ${peerId.toString()} for ${subProtocol}`);
} catch (closeError) {
this.logger.error(
`Error closing stream: ${closeError instanceof Error ? closeError.message : 'Unknown error'}`,
Expand Down
2 changes: 1 addition & 1 deletion yarn-project/sequencer-client/src/sequencer/sequencer.ts
Original file line number Diff line number Diff line change
Expand Up @@ -713,7 +713,7 @@ export class Sequencer {
this.log.debug('Creating block proposal');
const proposal = await this.validatorClient.createBlockProposal(block.header, block.archive.root, txHashes);
if (!proposal) {
this.log.verbose(`Failed to create block proposal, skipping`);
this.log.verbose(`Failed to create block proposal, skipping collecting attestations`);
return undefined;
}

Expand Down
47 changes: 28 additions & 19 deletions yarn-project/validator-client/src/validator.ts
Original file line number Diff line number Diff line change
Expand Up @@ -127,6 +127,16 @@ export class ValidatorClient extends WithTracer implements Validator {
}

async attestToProposal(proposal: BlockProposal): Promise<BlockAttestation | undefined> {
const slotNumber = proposal.slotNumber.toNumber();
const proposalInfo = {
slotNumber,
blockNumber: proposal.payload.header.globalVariables.blockNumber.toNumber(),
archive: proposal.payload.archive.toString(),
txCount: proposal.payload.txHashes.length,
txHashes: proposal.payload.txHashes.map(txHash => txHash.toString()),
};
this.log.verbose(`Received request to attest for slot ${slotNumber}`);

// Check that I am in the committee
if (!(await this.epochCache.isInCommittee(this.keyStore.getAddress()))) {
this.log.verbose(`Not in the committee, skipping attestation`);
Expand All @@ -150,10 +160,7 @@ export class ValidatorClient extends WithTracer implements Validator {
}

// Check that all of the tranasctions in the proposal are available in the tx pool before attesting
this.log.verbose(`request to attest`, {
archive: proposal.payload.archive.toString(),
txHashes: proposal.payload.txHashes.map(txHash => txHash.toString()),
});
this.log.verbose(`Processing attestation for slot ${slotNumber}`, proposalInfo);
try {
await this.ensureTransactionsAreAvailable(proposal);

Expand All @@ -164,19 +171,17 @@ export class ValidatorClient extends WithTracer implements Validator {
} catch (error: any) {
// If the transactions are not available, then we should not attempt to attest
if (error instanceof TransactionsNotAvailableError) {
this.log.error(`Transactions not available, skipping attestation ${error.message}`);
this.log.error(`Transactions not available, skipping attestation`, error, proposalInfo);
} else {
// This branch most commonly be hit if the transactions are available, but the re-execution fails
// Catch all error handler
this.log.error(`Failed to attest to proposal: ${error.message}`);
this.log.error(`Failed to attest to proposal`, error, proposalInfo);
}
return undefined;
}

// Provided all of the above checks pass, we can attest to the proposal
this.log.verbose(
`Transactions available, attesting to proposal with ${proposal.payload.txHashes.length} transactions`,
);
this.log.info(`Attesting to proposal for slot ${slotNumber}`, proposalInfo);

// If the above function does not throw an error, then we can attest to the proposal
return this.validationService.attestToProposal(proposal);
Expand All @@ -195,7 +200,6 @@ export class ValidatorClient extends WithTracer implements Validator {

// If we cannot request all of the transactions, then we should fail
if (txs.length !== txHashes.length) {
this.log.error(`Failed to get transactions from the network: ${txHashes.join(', ')}`);
throw new TransactionsNotAvailableError(txHashes);
}

Expand All @@ -209,7 +213,7 @@ export class ValidatorClient extends WithTracer implements Validator {
const { block } = await this.blockBuilder(txs, header.globalVariables);
stopTimer();

this.log.verbose(`Re-ex: Re-execution complete`);
this.log.verbose(`Transaction re-execution complete`);

// This function will throw an error if state updates do not match
if (!block.archive.root.equals(proposal.archive)) {
Expand Down Expand Up @@ -240,7 +244,6 @@ export class ValidatorClient extends WithTracer implements Validator {

const requestedTxs = await this.p2pClient.requestTxs(missingTxs);
if (requestedTxs.some(tx => tx === undefined)) {
this.log.error(`Failed to request transactions from the network: ${missingTxs.join(', ')}`);
throw new TransactionsNotAvailableError(missingTxs);
}
}
Expand All @@ -267,30 +270,36 @@ export class ValidatorClient extends WithTracer implements Validator {
): Promise<BlockAttestation[]> {
// Wait and poll the p2pClient's attestation pool for this block until we have enough attestations
const slot = proposal.payload.header.globalVariables.slotNumber.toBigInt();
this.log.info(`Waiting for ${numberOfRequiredAttestations} attestations for slot: ${slot}`);
this.log.debug(`Collecting ${numberOfRequiredAttestations} attestations for slot ${slot}`);

const proposalId = proposal.archive.toString();
const myAttestation = await this.validationService.attestToProposal(proposal);

const startTime = Date.now();

let attestations: BlockAttestation[] = [];
while (true) {
const attestations = [myAttestation, ...(await this.p2pClient.getAttestationsForSlot(slot, proposalId))];
const collectedAttestations = [myAttestation, ...(await this.p2pClient.getAttestationsForSlot(slot, proposalId))];
const newAttestations = collectedAttestations.filter(
collected => !attestations.some(old => old.getSender().equals(collected.getSender())),
);
for (const attestation of newAttestations) {
this.log.debug(`Received attestation for slot ${slot} from ${attestation.getSender().toString()}`);
}
attestations = collectedAttestations;

if (attestations.length >= numberOfRequiredAttestations) {
this.log.info(`Collected all ${numberOfRequiredAttestations} attestations for slot, ${slot}`);
this.log.verbose(`Collected all ${numberOfRequiredAttestations} attestations for slot ${slot}`);
return attestations;
}

const elapsedTime = Date.now() - startTime;
if (elapsedTime > this.config.attestationWaitTimeoutMs) {
this.log.error(`Timeout waiting for ${numberOfRequiredAttestations} attestations for slot, ${slot}`);
this.log.error(`Timeout waiting for ${numberOfRequiredAttestations} attestations for slot ${slot}`);
throw new AttestationTimeoutError(numberOfRequiredAttestations, slot);
}

this.log.verbose(
`Collected ${attestations.length} attestations so far, waiting ${this.config.attestationPollingIntervalMs}ms for more...`,
);
this.log.debug(`Collected ${attestations.length} attestations so far`);
await sleep(this.config.attestationPollingIntervalMs);
}
}
Expand Down
Loading