diff --git a/package.json b/package.json index 6806352..e45cc3b 100644 --- a/package.json +++ b/package.json @@ -26,6 +26,8 @@ "get-block::devnet": "NODE_NO_WARNINGS=1 AZTEC_ENV=devnet node --loader ts-node/esm scripts/get_block.ts", "profile": "NODE_NO_WARNINGS=1 node --loader ts-node/esm scripts/profile_deploy.ts", "profile::devnet": "NODE_NO_WARNINGS=1 AZTEC_ENV=devnet node --loader ts-node/esm scripts/profile_deploy.ts", + "read-logs": "NODE_NO_WARNINGS=1 LOG_LEVEL='info; debug:contract_log' node --loader ts-node/esm scripts/read_debug_logs.ts", + "read-logs::devnet": "NODE_NO_WARNINGS=1 LOG_LEVEL='info; debug:contract_log' AZTEC_ENV=devnet node --loader ts-node/esm scripts/read_debug_logs.ts", "test": "yarn test:js && yarn test:nr", "test::devnet": "AZTEC_ENV=devnet yarn test:js", "test:js": "rm -rf store/pxe && NODE_NO_WARNINGS=1 node --experimental-vm-modules $(yarn bin jest) --no-cache --runInBand --config jest.integration.config.json", diff --git a/scripts/read_debug_logs.ts b/scripts/read_debug_logs.ts new file mode 100644 index 0000000..77d7b1e --- /dev/null +++ b/scripts/read_debug_logs.ts @@ -0,0 +1,134 @@ +// Reads debug logs from PodRacing contract transactions. +// +// debug_log_format calls in both contract functions and utility functions emit +// through the PXE oracle during .simulate() and through the node during .send(). +// Set LOG_LEVEL to see them in stdout: +// +// LOG_LEVEL='info; debug:contract_log' yarn read-logs +// +// Or for maximum verbosity: +// +// LOG_LEVEL=debug yarn read-logs + +import { PodRacingContract } from "../src/artifacts/PodRacing.js"; +import { createLogger } from "@aztec/foundation/log"; +import { SponsoredFeePaymentMethod } from "@aztec/aztec.js/fee"; +import { SponsoredFPCContractArtifact } from "@aztec/noir-contracts.js/SponsoredFPC"; +import { AztecAddress } from "@aztec/aztec.js/addresses"; +import { Fr } from "@aztec/aztec.js/fields"; +import { GrumpkinScalar } from "@aztec/foundation/curves/grumpkin"; +import { setupWallet } from "../src/utils/setup_wallet.js"; +import { getSponsoredFPCInstance } from "../src/utils/sponsored_fpc.js"; +import { getTimeouts } from "../config/config.js"; + +async function main() { + const logger = createLogger('aztec:aztec-starter:debug-logs'); + const timeouts = getTimeouts(); + + // Setup + logger.info('Setting up wallet and accounts...'); + const wallet = await setupWallet(); + + const sponsoredFPC = await getSponsoredFPCInstance(); + await wallet.registerContract(sponsoredFPC, SponsoredFPCContractArtifact); + const paymentMethod = new SponsoredFeePaymentMethod(sponsoredFPC.address); + + // Create two player accounts + const p1Account = await wallet.createSchnorrAccount(Fr.random(), Fr.random(), GrumpkinScalar.random()); + await (await p1Account.getDeployMethod()).send({ + from: AztecAddress.ZERO, + fee: { paymentMethod }, + wait: { timeout: timeouts.deployTimeout }, + }); + + const p2Account = await wallet.createSchnorrAccount(Fr.random(), Fr.random(), GrumpkinScalar.random()); + await (await p2Account.getDeployMethod()).send({ + from: AztecAddress.ZERO, + fee: { paymentMethod }, + wait: { timeout: timeouts.deployTimeout }, + }); + + await wallet.registerSender(p1Account.address, 'player1'); + await wallet.registerSender(p2Account.address, 'player2'); + logger.info(`Player 1: ${p1Account.address}`); + logger.info(`Player 2: ${p2Account.address}`); + + // Deploy contract — constructor has debug_log_format + logger.info('\n--- Deploying PodRacing contract (constructor logs) ---'); + const deployRequest = PodRacingContract.deploy(wallet, p1Account.address); + await deployRequest.simulate({ from: p1Account.address }); + const contract = await deployRequest.send({ + from: p1Account.address, + fee: { paymentMethod }, + wait: { timeout: timeouts.deployTimeout }, + }); + logger.info(`Contract deployed at: ${contract.address}`); + + const gameId = Fr.random(); + const sendOpts = (from: AztecAddress) => ({ + from, + fee: { paymentMethod }, + wait: { timeout: timeouts.txTimeout }, + }); + + // create_game (public) — logs: "Creating game {0} by player {1}" + logger.info('\n--- create_game (public function logs) ---'); + await contract.methods.create_game(gameId).simulate({ from: p1Account.address }); + await contract.methods.create_game(gameId).send(sendOpts(p1Account.address)); + logger.info('create_game complete'); + + // join_game (public) — logs: "Player {0} joining game {1}" + logger.info('\n--- join_game (public function logs) ---'); + await contract.methods.join_game(gameId).simulate({ from: p2Account.address }); + await contract.methods.join_game(gameId).send(sendOpts(p2Account.address)); + logger.info('join_game complete'); + + // play_round (private -> enqueues public) — logs track allocations + validation + const allocations = [ + [3, 2, 2, 1, 1], + [1, 1, 3, 2, 2], + [2, 2, 1, 2, 2], + ]; + + for (let round = 1; round <= 3; round++) { + const [t1, t2, t3, t4, t5] = allocations[round - 1]; + + logger.info(`\n--- play_round ${round} player 1 (private + public logs) ---`); + await contract.methods.play_round(gameId, round, t1, t2, t3, t4, t5).simulate({ from: p1Account.address }); + await contract.methods.play_round(gameId, round, t1, t2, t3, t4, t5).send(sendOpts(p1Account.address)); + + logger.info(`\n--- play_round ${round} player 2 (private + public logs) ---`); + await contract.methods.play_round(gameId, round, t5, t4, t3, t2, t1).simulate({ from: p2Account.address }); + await contract.methods.play_round(gameId, round, t5, t4, t3, t2, t1).send(sendOpts(p2Account.address)); + } + + // finish_game (private -> enqueues public) — logs computed totals + reveal + logger.info('\n--- finish_game player 1 (private + public logs) ---'); + await contract.methods.finish_game(gameId).simulate({ from: p1Account.address }); + await contract.methods.finish_game(gameId).send(sendOpts(p1Account.address)); + + logger.info('\n--- finish_game player 2 (private + public logs) ---'); + await contract.methods.finish_game(gameId).simulate({ from: p2Account.address }); + await contract.methods.finish_game(gameId).send(sendOpts(p2Account.address)); + + // debug_game_state (utility function) — runs client-side in PXE, not on-chain. + // Calls Race.log_race_state which uses debug_log_format. + // Utility function logs go through the UtilityExecutionOracle and are emitted + // immediately through the structured logger, just like private function logs. + logger.info('\n--- debug_game_state (utility function — runs in PXE) ---'); + await contract.methods.debug_game_state(gameId).simulate({ from: p1Account.address }); + logger.info('Utility function simulation complete'); + + logger.info('\n=== Done ==='); + logger.info('Utility function debug_log_format calls (debug_game_state) run client-side in'); + logger.info('the PXE and their logs appear in stdout via the UtilityExecutionOracle.'); +} + +main() + .then(() => process.exit(0)) + .catch((error) => { + const logger = createLogger('aztec:aztec-starter:debug-logs'); + logger.error(`Failed: ${error.message}`); + logger.error(error.stack); + process.exit(1); + }); diff --git a/src/main.nr b/src/main.nr index 288d004..a8d74b8 100644 --- a/src/main.nr +++ b/src/main.nr @@ -276,4 +276,14 @@ pub contract PodRacing { ); self.storage.win_history.at(winner).write(previous_wins + 1); } + + // Utility function: runs client-side in the PXE, not on-chain. + // Reads the public game state and logs it via debug_log_format. + #[external("utility")] + unconstrained fn debug_game_state(game_id: Field) { + let race = self.storage.races.at(game_id).read(); + debug_log_format("=== debug_game_state utility for game {0} ===", [game_id]); + race.log_race_state(game_id); + debug_log_format("=== end debug_game_state ===", [game_id]); + } } diff --git a/src/race.nr b/src/race.nr index c0e07cf..ec0370b 100644 --- a/src/race.nr +++ b/src/race.nr @@ -1,6 +1,7 @@ +use ::aztec::oracle::logging::debug_log_format; use ::aztec::protocol::{ address::AztecAddress, - traits::{Deserialize, Serialize, Packable}, + traits::{Deserialize, Serialize, Packable, ToField}, }; // Race struct stores the public state of a game @@ -210,6 +211,45 @@ impl Race { ret.unwrap() } + // Logs the full state of a race for debugging + pub fn log_race_state(self, label: Field) { + debug_log_format("=== Race State ({0}) ===", [label]); + debug_log_format( + "Players: p1={0}, p2={1}", + [self.player1.to_field(), self.player2.to_field()], + ); + debug_log_format( + "Rounds: p1={0}/{1}, p2={2}/{3}", + [ + self.player1_round as Field, + self.total_rounds as Field, + self.player2_round as Field, + self.total_rounds as Field, + ], + ); + debug_log_format( + "P1 tracks: {0}, {1}, {2}, {3}, {4}", + [ + self.player1_track1_final as Field, + self.player1_track2_final as Field, + self.player1_track3_final as Field, + self.player1_track4_final as Field, + self.player1_track5_final as Field, + ], + ); + debug_log_format( + "P2 tracks: {0}, {1}, {2}, {3}, {4}", + [ + self.player2_track1_final as Field, + self.player2_track2_final as Field, + self.player2_track3_final as Field, + self.player2_track4_final as Field, + self.player2_track5_final as Field, + ], + ); + debug_log_format("End block: {0}", [self.end_block as Field]); + } + // Determines the game winner by comparing track scores // Winner is whoever won more tracks (best of 5) //