diff --git a/.github/workflows/_40_post_check.yml b/.github/workflows/_40_post_check.yml index a69d3390f3..3f2e1eee66 100644 --- a/.github/workflows/_40_post_check.yml +++ b/.github/workflows/_40_post_check.yml @@ -202,6 +202,15 @@ jobs: /tmp/chainflip/debug.*log /tmp/solana/*.*log + - name: Upload Bouncer Logs 💾 + if: always() + continue-on-error: true + uses: actions/upload-artifact@50769540e7f4bd5e21e526ee35c689e35e0d6874 + with: + name: bouncer-logs + path: | + /tmp/chainflip/bouncer.log + - name: List /tmp/chainflip 📂 if: always() continue-on-error: true diff --git a/.github/workflows/upgrade-test.yml b/.github/workflows/upgrade-test.yml index f9ee64339e..f38ecb2696 100644 --- a/.github/workflows/upgrade-test.yml +++ b/.github/workflows/upgrade-test.yml @@ -285,6 +285,15 @@ jobs: path: | /tmp/chainflip/logs/*.log + - name: Upload Bouncer Logs 💾 + if: always() + continue-on-error: true + uses: actions/upload-artifact@50769540e7f4bd5e21e526ee35c689e35e0d6874 + with: + name: bouncer-logs-upgrade-test + path: | + /tmp/chainflip/bouncer.log + - name: Write chain explorer to file 📝 if: failure() continue-on-error: true diff --git a/bouncer/README.md b/bouncer/README.md index fde0c1a8c1..b036cad9fc 100644 --- a/bouncer/README.md +++ b/bouncer/README.md @@ -103,12 +103,18 @@ describe('ConcurrentTests', () => { }); ``` -Now that the test is added, we can run it using the `vitest` command. +Now that the test is added, we can run it using the `vitest` command: ```sh copy pnpm vitest run -t "myNewTest" ``` +You can use `vitest`s `list` command to find the name of that test you what to run: + +```sh copy +pnpm vitest list +``` + If your test uses the `SwapContext` within the `TestContext`, then the report will be automatically logged when the test finishes. If you would like to run your test with custom arguments, then you will have to create a test command file. See the `test_commands` folder for examples. @@ -122,3 +128,89 @@ pnpm vitest run -t "ConcurrentTests" # run all tests in a file pnpm vitest run -t ./tests/fast_bouncer.test.ts ``` + +## Logging + +In the bouncer we use `Pino` as our logging framework. It has been configured to output the logs to: + +- `stdout` at `INFO` level in pretty format +- `/tmp/chainflip/bouncer.log` at `TRACE` level in `JSON` format + +Note: To keep the `stdout` clean, that output is configured to ignore the common `test`, `tag` and `module` bindings that ar attached to log messages. + +### Logging in a test + +Use the `Logger` that is attached to the `TestContext`. +This logger already has the name of the test attached to it. +Do not use `console.log` as it will not be logged to the file. + +```ts +import { TestContext } from '../shared/utils/test_context'; +import { Logger, throwError } from '../shared/utils/logger'; + +async function testCase(parentLogger: Logger, asset: Asset) { + // Attach any contextual data to the logger as a binding. {"inputAsset": "Eth"}. + const logger = parentLogger.child({ inputAsset: asset }); + + // Basic logging + logger.debug('About to foo'); + + // Throwing an error with all of the loggers contextual data (bindings) added to the error message. + // No need to catch this, it will be logged as at `Error` level. + if (foo) { + throwError(logger, new Error('Foo happened')); + } +} + +export async function myTest(testContext: TestContext) { + await testCase(testContext.logger, 'Eth'); + + // You can log directly from the `TestContext` as well + testContext.info('Goodbye'); +} +``` + +Another option for adding information to the logger is using the custom `loggerChild` function. +This will append the given string to the `module` binding. + +```ts +import { loggerChild } from '../shared/utils/logger'; + +const logger1 = loggerChild(parentLogger, `myTestCase`); +const logger2 = loggerChild(logger1, `setupFunction`); +const logger3 = loggerChild(logger2, `myFunction`); +logger3.info('This message will have the full module path attached'); +// {"module": `myTestCase::setupFunction::myFunction`} +``` + +### Logging outside of a test + +If you need to use the logger in a command or any other non-test code, you can use the `globalLogger`. +It has no bindings attached to it. +It will still output to both `stdout` and the `bouncer.log` file. + +```ts +import { globalLogger } from '../shared/utils/logger'; + +globalLogger.info('Executing my command'); +await observeEvent(globalLogger, 'someEvent'); +``` + +### Debugging + +To debug a failed test you can use the `bouncer.log` file. It will have logs at `Trace` level of all test that where ran. +To filter for the test you are debugging, you can use the `test` value that should be on all log messages (Excluding logs from commands, setup scripts and thrown errors). + +An example of using `jq` to filter the logs for an individual test and put them in another file: + +```sh copy +jq 'select(.test=="BoostingForAsset")' /tmp/chainflip/bouncer.log > /tmp/chainflip/failed_test.log +``` + +If you want to run a test and have the `stdout` logs be at different level, you can use the `BOUNCER_LOG_LEVEL` environment variable (Does not effect the `bouncer.log` file). + +```sh copy +BOUNCER_LOG_LEVEL=debug pnpm vitest run -t "BoostingForAsset" +``` + +Note: you can use the `BOUNCER_LOG_PATH` environment variable to output the logs to a different file. diff --git a/bouncer/commands/add_boost_funds.ts b/bouncer/commands/add_boost_funds.ts index 65e18c64c3..47349296d7 100755 --- a/bouncer/commands/add_boost_funds.ts +++ b/bouncer/commands/add_boost_funds.ts @@ -13,9 +13,11 @@ import { InternalAsset as Asset } from '@chainflip/cli'; import { runWithTimeoutAndExit } from '../shared/utils'; import { addBoostFunds } from '../tests/boost'; +import { globalLogger } from '../shared/utils/logger'; await runWithTimeoutAndExit( addBoostFunds( + globalLogger, process.argv[2] as Asset, Number(process.argv[3]), Number(process.argv[4]), diff --git a/bouncer/commands/check_bin_and_runtime_versions.ts b/bouncer/commands/check_bin_and_runtime_versions.ts index f8b4e16816..cba478e1df 100755 --- a/bouncer/commands/check_bin_and_runtime_versions.ts +++ b/bouncer/commands/check_bin_and_runtime_versions.ts @@ -2,13 +2,10 @@ import fs from 'fs'; import toml from '@iarna/toml'; -import { compareSemVer } from '../shared/utils'; +import { compareSemVer, runWithTimeoutAndExit } from '../shared/utils'; import { jsonRpc } from '../shared/json_rpc'; import { specVersion } from '../shared/utils/spec_version'; - -const projectRoot = process.argv[2]; -const engineReleaseVersion = process.argv[3]; -const network = process.argv[4]; +import { globalLogger as logger } from '../shared/utils/logger'; export function tomlVersion(cargoFilePath: string): Promise { return new Promise((resolve, reject) => { @@ -29,82 +26,94 @@ export function tomlVersion(cargoFilePath: string): Promise { }); } -const versionRegex = /\d+\.\d+\.\d+/; -const releaseVersion = engineReleaseVersion.match(versionRegex)?.[0]; -if (!releaseVersion) { - throw Error('Invalid release version'); -} +async function main() { + const projectRoot = process.argv[2]; + const engineReleaseVersion = process.argv[3]; + const network = process.argv[4]; -// Ensure all the versions are the same -const engineTomlVersion = await tomlVersion(`${projectRoot}/engine/Cargo.toml`); -const runtimeTomlVersion = await tomlVersion(`${projectRoot}/state-chain/runtime/Cargo.toml`); -const nodeTomlVersion = await tomlVersion(`${projectRoot}/state-chain/node/Cargo.toml`); -const cliTomlVersion = await tomlVersion(`${projectRoot}/api/bin/chainflip-cli/Cargo.toml`); -const lpApiTomlVersion = await tomlVersion(`${projectRoot}/api/bin/chainflip-lp-api/Cargo.toml`); -const apiLibTomlVersion = await tomlVersion(`${projectRoot}/api/lib/Cargo.toml`); -const runnerTomlVersion = await tomlVersion(`${projectRoot}/engine-runner-bin/Cargo.toml`); -const dylibTomlVersion = await tomlVersion(`${projectRoot}/engine-dylib/Cargo.toml`); -// The engine gets the version from this file -const procMacrosVersion = await tomlVersion(`${projectRoot}/engine-proc-macros/Cargo.toml`); + const versionRegex = /\d+\.\d+\.\d+/; + const releaseVersion = engineReleaseVersion.match(versionRegex)?.[0]; + if (!releaseVersion) { + throw Error('Invalid release version'); + } -const brokerTomlVersion = await tomlVersion( - `${projectRoot}/api/bin/chainflip-broker-api/Cargo.toml`, -); + // Ensure all the versions are the same + const engineTomlVersion = await tomlVersion(`${projectRoot}/engine/Cargo.toml`); + const runtimeTomlVersion = await tomlVersion(`${projectRoot}/state-chain/runtime/Cargo.toml`); + const nodeTomlVersion = await tomlVersion(`${projectRoot}/state-chain/node/Cargo.toml`); + const cliTomlVersion = await tomlVersion(`${projectRoot}/api/bin/chainflip-cli/Cargo.toml`); + const lpApiTomlVersion = await tomlVersion(`${projectRoot}/api/bin/chainflip-lp-api/Cargo.toml`); + const apiLibTomlVersion = await tomlVersion(`${projectRoot}/api/lib/Cargo.toml`); + const runnerTomlVersion = await tomlVersion(`${projectRoot}/engine-runner-bin/Cargo.toml`); + const dylibTomlVersion = await tomlVersion(`${projectRoot}/engine-dylib/Cargo.toml`); + // The engine gets the version from this file + const procMacrosVersion = await tomlVersion(`${projectRoot}/engine-proc-macros/Cargo.toml`); -if ( - !( - engineTomlVersion === runtimeTomlVersion && - runtimeTomlVersion === nodeTomlVersion && - nodeTomlVersion === cliTomlVersion && - cliTomlVersion === lpApiTomlVersion && - lpApiTomlVersion === brokerTomlVersion && - apiLibTomlVersion === brokerTomlVersion && - brokerTomlVersion === runnerTomlVersion && - runnerTomlVersion === dylibTomlVersion && - dylibTomlVersion === procMacrosVersion - ) -) { - throw Error('All versions should be the same'); -} else if (compareSemVer(engineTomlVersion, releaseVersion) === 'greater') { - console.log( - `Binary versions are correct. Your branch has version ${engineTomlVersion} greater than the current release ${releaseVersion}.`, - ); -} else { - throw Error( - `Binary versions are incorrect. The version of your branch (${engineTomlVersion}) should be greater than the current release (${releaseVersion}).)`, + const brokerTomlVersion = await tomlVersion( + `${projectRoot}/api/bin/chainflip-broker-api/Cargo.toml`, ); -} -let endpoint; -switch (network) { - case 'mainnet': - case 'berghain': - endpoint = 'https://mainnet-archive.chainflip.io:443'; - break; - case 'perseverance': - endpoint = 'https://perseverance.chainflip.xyz:443'; - break; - case 'sisyphos': - endpoint = 'https://archive.sisyphos.chainflip.io:443'; - break; - default: - throw Error('Invalid network'); -} + if ( + !( + engineTomlVersion === runtimeTomlVersion && + runtimeTomlVersion === nodeTomlVersion && + nodeTomlVersion === cliTomlVersion && + cliTomlVersion === lpApiTomlVersion && + lpApiTomlVersion === brokerTomlVersion && + apiLibTomlVersion === brokerTomlVersion && + brokerTomlVersion === runnerTomlVersion && + runnerTomlVersion === dylibTomlVersion && + dylibTomlVersion === procMacrosVersion + ) + ) { + throw Error('All versions should be the same'); + } else if (compareSemVer(engineTomlVersion, releaseVersion) === 'greater') { + logger.info( + `Binary versions are correct. Your branch has version ${engineTomlVersion} greater than the current release ${releaseVersion}.`, + ); + } else { + throw Error( + `Binary versions are incorrect. The version of your branch (${engineTomlVersion}) should be greater than the current release (${releaseVersion}).)`, + ); + } -const releaseSpecVersion = Number( - ((await jsonRpc('state_getRuntimeVersion', [], endpoint)) as any).specVersion, -); -console.log(`Release spec version: ${releaseSpecVersion}`); + let endpoint; + switch (network) { + case 'mainnet': + case 'berghain': + endpoint = 'https://mainnet-archive.chainflip.io:443'; + break; + case 'perseverance': + endpoint = 'https://perseverance.chainflip.xyz:443'; + break; + case 'sisyphos': + endpoint = 'https://archive.sisyphos.chainflip.io:443'; + break; + default: + throw Error('Invalid network'); + } -const specVersionInSource = specVersion(`${projectRoot}/state-chain/runtime/src/lib.rs`, 'read'); -console.log(`Spec version in runtime/src/lib.rs: ${specVersionInSource}`); - -if (specVersionInSource >= releaseSpecVersion) { - console.log( - `Spec version is correct. Version in TOML is greater than or equal to the release spec version.`, + const releaseSpecVersion = Number( + ((await jsonRpc(logger, 'state_getRuntimeVersion', [], endpoint)) as any).specVersion, ); -} else { - throw Error( - `Spec version is incorrect. Version in TOML (${specVersionInSource}) should be greater than or equal to the release spec version (${releaseSpecVersion}).`, + logger.info(`Release spec version: ${releaseSpecVersion}`); + + const specVersionInSource = specVersion( + logger, + `${projectRoot}/state-chain/runtime/src/lib.rs`, + 'read', ); + logger.info(`Spec version in runtime/src/lib.rs: ${specVersionInSource}`); + + if (specVersionInSource >= releaseSpecVersion) { + logger.info( + `Spec version is correct. Version in TOML is greater than or equal to the release spec version.`, + ); + } else { + throw Error( + `Spec version is incorrect. Version in TOML (${specVersionInSource}) should be greater than or equal to the release spec version (${releaseSpecVersion}).`, + ); + } } + +await runWithTimeoutAndExit(main(), 60); diff --git a/bouncer/commands/create_boost_pools.ts b/bouncer/commands/create_boost_pools.ts index 676bd97333..e5a38e8b32 100755 --- a/bouncer/commands/create_boost_pools.ts +++ b/bouncer/commands/create_boost_pools.ts @@ -10,6 +10,7 @@ import { runWithTimeoutAndExit } from '../shared/utils'; import { BoostPoolId, createBoostPools } from '../shared/setup_boost_pools'; +import { globalLogger } from '../shared/utils/logger'; const newPools: BoostPoolId[] = JSON.parse(process.argv[2]); -await runWithTimeoutAndExit(createBoostPools(newPools), 30); +await runWithTimeoutAndExit(createBoostPools(globalLogger, newPools), 30); diff --git a/bouncer/commands/create_lp_pool.ts b/bouncer/commands/create_lp_pool.ts index a7adc28326..cb35f817b1 100755 --- a/bouncer/commands/create_lp_pool.ts +++ b/bouncer/commands/create_lp_pool.ts @@ -8,7 +8,8 @@ import { createLpPool } from '../shared/create_lp_pool'; import { parseAssetString, runWithTimeoutAndExit } from '../shared/utils'; +import { globalLogger } from '../shared/utils/logger'; const initialPrice = parseFloat(process.argv[3]); const asset = parseAssetString(process.argv[2]); -await runWithTimeoutAndExit(createLpPool(asset, initialPrice), 20); +await runWithTimeoutAndExit(createLpPool(globalLogger, asset, initialPrice), 20); diff --git a/bouncer/commands/delete_all_orders_lp_api.ts b/bouncer/commands/delete_all_orders_lp_api.ts index 42e957dd35..b77036a1a7 100755 --- a/bouncer/commands/delete_all_orders_lp_api.ts +++ b/bouncer/commands/delete_all_orders_lp_api.ts @@ -6,9 +6,10 @@ import { runWithTimeoutAndExit } from '../shared/utils'; import { DeleteAllOrdersLpApi } from '../shared/delete_all_orders_lp_api'; +import { globalLogger } from '../shared/utils/logger'; async function main(): Promise { - await DeleteAllOrdersLpApi(); + await DeleteAllOrdersLpApi(globalLogger); } await runWithTimeoutAndExit(main(), 240); diff --git a/bouncer/commands/deposit_liquidity.ts b/bouncer/commands/deposit_liquidity.ts index 89ab6e0c07..db7d632b39 100755 --- a/bouncer/commands/deposit_liquidity.ts +++ b/bouncer/commands/deposit_liquidity.ts @@ -11,8 +11,12 @@ import { InternalAsset } from '@chainflip/cli'; import { parseAssetString, runWithTimeoutAndExit } from '../shared/utils'; import { depositLiquidity } from '../shared/deposit_liquidity'; +import { globalLogger } from '../shared/utils/logger'; const asset = parseAssetString(process.argv[2]); const amount = parseFloat(process.argv[3]); const lpKey = process.argv[4]; -await runWithTimeoutAndExit(depositLiquidity(asset as InternalAsset, amount, false, lpKey), 120); +await runWithTimeoutAndExit( + depositLiquidity(globalLogger, asset as InternalAsset, amount, false, lpKey), + 120, +); diff --git a/bouncer/shared/force_sol_nonces.ts b/bouncer/commands/force_sol_nonces.ts similarity index 100% rename from bouncer/shared/force_sol_nonces.ts rename to bouncer/commands/force_sol_nonces.ts diff --git a/bouncer/commands/fund_flip.ts b/bouncer/commands/fund_flip.ts index 20e8d2c859..abceaebb59 100755 --- a/bouncer/commands/fund_flip.ts +++ b/bouncer/commands/fund_flip.ts @@ -11,7 +11,8 @@ import { runWithTimeoutAndExit } from '../shared/utils'; import { fundFlip } from '../shared/fund_flip'; +import { globalLogger } from '../shared/utils/logger'; const address = process.argv[2]; const flipAmount = process.argv[3].trim(); -await runWithTimeoutAndExit(fundFlip(address, flipAmount), 120); +await runWithTimeoutAndExit(fundFlip(globalLogger, address, flipAmount), 120); diff --git a/bouncer/commands/go_bananas.ts b/bouncer/commands/go_bananas.ts index f6aa29b5cd..3cfa10e2a2 100755 --- a/bouncer/commands/go_bananas.ts +++ b/bouncer/commands/go_bananas.ts @@ -20,6 +20,7 @@ import { sendBtc } from '../shared/send_btc'; import { createLpPool } from '../shared/create_lp_pool'; import { depositLiquidity } from '../shared/deposit_liquidity'; import { getChainflipApi } from '../shared/utils/substrate'; +import { globalLogger as logger } from '../shared/utils/logger'; // eslint-disable-next-line @typescript-eslint/no-explicit-any async function call(method: string, params: any, id: string) { @@ -81,7 +82,7 @@ let chainflip = await getChainflipApi(); let pubkey = ((await chainflip.query.environment.polkadotVaultAccountId()).toJSON()! as string).substring(2); let salt = ((await chainflip.query.polkadotIngressEgress.channelIdCounter()).toJSON()! as number) + 1; let dot = predictDotAddress(pubkey, salt); -console.log(dot); */ +logger.info(dot); */ // eslint-disable-next-line @typescript-eslint/no-unused-vars function predictDotAddress(pubkey: string, salt: number): string { @@ -167,7 +168,7 @@ async function playLp(asset: Asset, price: number, liquidity: number) { ]); result.forEach((r) => { if (r.data.error) { - console.log(`Error [${r.data.id}]: ${JSON.stringify(r.data.error)}`); + logger.error(`[${r.data.id}]: ${JSON.stringify(r.data.error)}`); } else { r.data.result.tx_details.response.forEach((update: LimitOrderResponse) => { if (BigInt(update.collected_fees) > BigInt(0)) { @@ -181,7 +182,7 @@ async function playLp(asset: Asset, price: number, liquidity: number) { BigInt(update.collected_fees.toString()).toString(10), assetDecimals(ccy), ); - console.log(`Collected ${fees} ${ccy} in fees`); + logger.info(`Collected ${fees} ${ccy} in fees`); } if (BigInt(update.bought_amount) > BigInt(0)) { let buyCcy; @@ -197,7 +198,7 @@ async function playLp(asset: Asset, price: number, liquidity: number) { BigInt(update.bought_amount.toString()).toString(10), assetDecimals(buyCcy), ); - console.log(`Bought ${amount} ${buyCcy} for ${sellCcy}`); + logger.info(`Bought ${amount} ${buyCcy} for ${sellCcy}`); } }); } @@ -226,13 +227,13 @@ async function launchTornado() { assets[index1] = assets[index2]; assets[index2] = temp; } - let swap = await requestNewSwap(assets[0], 'Btc', btcAddress); + let swap = await requestNewSwap(logger, assets[0], 'Btc', btcAddress); for (let i = 0; i < assets.length - 1; i++) { - swap = await requestNewSwap(assets[i + 1], assets[i], swap.depositAddress); + swap = await requestNewSwap(logger, assets[i + 1], assets[i], swap.depositAddress); } - await requestNewSwap('Btc', assets[assets.length - 1], swap.depositAddress); - await sendBtc(btcAddress, 0.01); - console.log(btcAddress); + await requestNewSwap(logger, 'Btc', assets[assets.length - 1], swap.depositAddress); + await sendBtc(logger, btcAddress, 0.01); + logger.info(btcAddress); } const swapAmount = new Map([ @@ -254,7 +255,7 @@ async function playSwapper() { .filter((x) => x !== src) .at(Math.floor(Math.random() * (assets.length - 1)))!; /* eslint-disable @typescript-eslint/no-floating-promises */ - testSwap(src, dest, undefined, undefined, undefined, undefined, swapAmount.get(src)); + testSwap(logger, src, dest, undefined, undefined, undefined, undefined, swapAmount.get(src)); await sleep(5000); } } @@ -274,24 +275,24 @@ async function bananas() { const liquidityUsdc = 10000; await Promise.all([ - createLpPool('Eth', price.get('Eth')!), - createLpPool('Dot', price.get('Dot')!), - createLpPool('Btc', price.get('Btc')!), - createLpPool('Flip', price.get('Flip')!), - createLpPool('Usdt', price.get('Usdt')!), - createLpPool('ArbEth', price.get('ArbEth')!), - createLpPool('ArbUsdc', price.get('ArbUsdc')!), + createLpPool(logger, 'Eth', price.get('Eth')!), + createLpPool(logger, 'Dot', price.get('Dot')!), + createLpPool(logger, 'Btc', price.get('Btc')!), + createLpPool(logger, 'Flip', price.get('Flip')!), + createLpPool(logger, 'Usdt', price.get('Usdt')!), + createLpPool(logger, 'ArbEth', price.get('ArbEth')!), + createLpPool(logger, 'ArbUsdc', price.get('ArbUsdc')!), ]); await Promise.all([ - depositLiquidity('Usdc', 8 * liquidityUsdc), - depositLiquidity('Eth', (2 * liquidityUsdc) / price.get('Eth')!), - depositLiquidity('Dot', (2 * liquidityUsdc) / price.get('Dot')!), - depositLiquidity('Btc', (2 * liquidityUsdc) / price.get('Btc')!), - depositLiquidity('Flip', (2 * liquidityUsdc) / price.get('Flip')!), - depositLiquidity('Usdt', (2 * liquidityUsdc) / price.get('Usdt')!), - depositLiquidity('ArbEth', (2 * liquidityUsdc) / price.get('ArbEth')!), - depositLiquidity('ArbUsdc', (2 * liquidityUsdc) / price.get('ArbUsdc')!), + depositLiquidity(logger, 'Usdc', 8 * liquidityUsdc), + depositLiquidity(logger, 'Eth', (2 * liquidityUsdc) / price.get('Eth')!), + depositLiquidity(logger, 'Dot', (2 * liquidityUsdc) / price.get('Dot')!), + depositLiquidity(logger, 'Btc', (2 * liquidityUsdc) / price.get('Btc')!), + depositLiquidity(logger, 'Flip', (2 * liquidityUsdc) / price.get('Flip')!), + depositLiquidity(logger, 'Usdt', (2 * liquidityUsdc) / price.get('Usdt')!), + depositLiquidity(logger, 'ArbEth', (2 * liquidityUsdc) / price.get('ArbEth')!), + depositLiquidity(logger, 'ArbUsdc', (2 * liquidityUsdc) / price.get('ArbUsdc')!), ]); await Promise.all([ diff --git a/bouncer/commands/new_swap.ts b/bouncer/commands/new_swap.ts index 14c16b9e48..952b509377 100755 --- a/bouncer/commands/new_swap.ts +++ b/bouncer/commands/new_swap.ts @@ -19,6 +19,7 @@ import { } from '../shared/utils'; import { requestNewSwap } from '../shared/perform_swap'; import { DcaParams, FillOrKillParamsX128 } from '../shared/new_swap'; +import { globalLogger } from '../shared/utils/logger'; interface Args { sourceAsset: string; @@ -121,13 +122,12 @@ async function newSwapCommand() { : undefined; await requestNewSwap( + globalLogger, parseAssetString(args.sourceAsset) as InternalAsset, parseAssetString(args.destAsset) as InternalAsset, args.destAddress, - undefined, // tag undefined, // messageMetadata undefined, // brokerCommissionBps - true, // log args.maxBoostFeeBps, refundParameters, dcaParameters, diff --git a/bouncer/commands/open_and_delete_orders.ts b/bouncer/commands/open_and_delete_orders.ts index 3463e6a745..7b119c00c9 100755 --- a/bouncer/commands/open_and_delete_orders.ts +++ b/bouncer/commands/open_and_delete_orders.ts @@ -8,7 +8,7 @@ // will create 5 limit_order and then delete them all with a single extrinsic import { runWithTimeoutAndExit } from '../shared/utils'; -import { logger } from '../shared/utils/logger'; +import { globalLogger } from '../shared/utils/logger'; import { createAndDeleteMultipleOrders } from '../tests/create_and_delete_multiple_orders'; async function main(): Promise { @@ -18,7 +18,7 @@ async function main(): Promise { } const numberOfOrders = process.argv[2]; - await createAndDeleteMultipleOrders(logger, Number(numberOfOrders)); + await createAndDeleteMultipleOrders(globalLogger, Number(numberOfOrders)); } await runWithTimeoutAndExit(main(), 240); diff --git a/bouncer/commands/perform_swap.ts b/bouncer/commands/perform_swap.ts index 4bc87010b4..f6258fbf53 100755 --- a/bouncer/commands/perform_swap.ts +++ b/bouncer/commands/perform_swap.ts @@ -2,12 +2,13 @@ import { InternalAsset } from '@chainflip/cli'; import { performSwap } from '../shared/perform_swap'; import { parseAssetString } from '../shared/utils'; +import { globalLogger } from '../shared/utils/logger'; async function main() { const srcCcy = parseAssetString(process.argv[2]); const dstCcy = parseAssetString(process.argv[3]); const address = process.argv[4]; - await performSwap(srcCcy as InternalAsset, dstCcy as InternalAsset, address); + await performSwap(globalLogger, srcCcy as InternalAsset, dstCcy as InternalAsset, address); process.exit(0); } diff --git a/bouncer/commands/polkadot_runtime_update.ts b/bouncer/commands/polkadot_runtime_update.ts index 399bddd152..56005ff208 100755 --- a/bouncer/commands/polkadot_runtime_update.ts +++ b/bouncer/commands/polkadot_runtime_update.ts @@ -11,17 +11,20 @@ import { } from '../tests/polkadot_runtime_update'; import { runWithTimeoutAndExit } from '../shared/utils'; import { getNetworkRuntimeVersion } from '../shared/utils/spec_version'; -import { logger } from '../shared/utils/logger'; +import { globalLogger } from '../shared/utils/logger'; async function main(): Promise { // Bump the spec version - const [wasmPath, expectedSpecVersion] = await bumpAndBuildPolkadotRuntime(logger); + const [wasmPath, expectedSpecVersion] = await bumpAndBuildPolkadotRuntime(globalLogger); // Submit the runtime update - await pushPolkadotRuntimeUpdate(wasmPath, logger); + await pushPolkadotRuntimeUpdate(globalLogger, wasmPath); // Check the polkadot spec version has changed - const postUpgradeSpecVersion = await getNetworkRuntimeVersion('http://127.0.0.1:9947'); + const postUpgradeSpecVersion = await getNetworkRuntimeVersion( + globalLogger, + 'http://127.0.0.1:9947', + ); if (postUpgradeSpecVersion.specVersion !== expectedSpecVersion) { throw new Error( `Polkadot runtime update failed. Currently at version ${postUpgradeSpecVersion.specVersion}, expected to be at ${expectedSpecVersion}`, diff --git a/bouncer/commands/range_order.ts b/bouncer/commands/range_order.ts index bcdf71520a..08697ed1e3 100755 --- a/bouncer/commands/range_order.ts +++ b/bouncer/commands/range_order.ts @@ -8,11 +8,12 @@ import { InternalAsset } from '@chainflip/cli'; import { rangeOrder } from '../shared/range_order'; import { parseAssetString, runWithTimeoutAndExit } from '../shared/utils'; +import { globalLogger } from '../shared/utils/logger'; async function main() { const ccy = parseAssetString(process.argv[2]); const amount = parseFloat(process.argv[3].trim()); - await rangeOrder(ccy as InternalAsset, amount); + await rangeOrder(globalLogger, ccy as InternalAsset, amount); } await runWithTimeoutAndExit(main(), 120); diff --git a/bouncer/commands/redeem_flip.ts b/bouncer/commands/redeem_flip.ts index b6c2b83461..a0bef03a69 100755 --- a/bouncer/commands/redeem_flip.ts +++ b/bouncer/commands/redeem_flip.ts @@ -13,6 +13,7 @@ import { HexString } from '@polkadot/util/types'; import { runWithTimeoutAndExit } from '../shared/utils'; import { RedeemAmount, redeemFlip } from '../shared/redeem_flip'; +import { globalLogger } from '../shared/utils/logger'; async function main(): Promise { const flipSeed = process.argv[2]; @@ -22,7 +23,7 @@ async function main(): Promise { const cleanFlipAmount: RedeemAmount = flipAmount === 'Max' ? 'Max' : { Exact: flipAmount.toString() }; - await redeemFlip(flipSeed, ethAddress, cleanFlipAmount); + await redeemFlip(globalLogger, flipSeed, ethAddress, cleanFlipAmount); } await runWithTimeoutAndExit(main(), 600); diff --git a/bouncer/commands/send.ts b/bouncer/commands/send.ts index f135e48847..2db6789a06 100755 --- a/bouncer/commands/send.ts +++ b/bouncer/commands/send.ts @@ -2,5 +2,6 @@ import { InternalAsset } from '@chainflip/cli'; import { send } from '../shared/send'; import { parseAssetString } from '../shared/utils'; +import { globalLogger } from '../shared/utils/logger'; -await send(parseAssetString(process.argv[2]) as InternalAsset, process.argv[3]); +await send(globalLogger, parseAssetString(process.argv[2]) as InternalAsset, process.argv[3]); diff --git a/bouncer/commands/send_arbeth.ts b/bouncer/commands/send_arbeth.ts index 985d6f10a0..b525667a52 100755 --- a/bouncer/commands/send_arbeth.ts +++ b/bouncer/commands/send_arbeth.ts @@ -10,13 +10,14 @@ import { runWithTimeoutAndExit } from '../shared/utils'; import { sendEvmNative } from '../shared/send_evm'; +import { globalLogger } from '../shared/utils/logger'; async function main() { const arbitrumAddress = process.argv[2]; const arbAmount = process.argv[3].trim(); - console.log('Transferring ' + arbAmount + ' ArbEth to ' + arbitrumAddress); - await sendEvmNative('Arbitrum', arbitrumAddress, arbAmount); + globalLogger.info(`Transferring ${arbAmount} ArbEth to ${arbitrumAddress}`); + await sendEvmNative(globalLogger, 'Arbitrum', arbitrumAddress, arbAmount); } await runWithTimeoutAndExit(main(), 20); diff --git a/bouncer/commands/send_arbusdc.ts b/bouncer/commands/send_arbusdc.ts index bc733e0bc8..11dd72fc9f 100755 --- a/bouncer/commands/send_arbusdc.ts +++ b/bouncer/commands/send_arbusdc.ts @@ -10,12 +10,13 @@ import { runWithTimeoutAndExit, getContractAddress } from '../shared/utils'; import { sendErc20 } from '../shared/send_erc20'; +import { globalLogger } from '../shared/utils/logger'; async function main(): Promise { const arbitrumAddress = process.argv[2]; const arbusdcAmount = process.argv[3].trim(); const contractAddress = getContractAddress('Arbitrum', 'ArbUsdc'); - await sendErc20('Arbitrum', arbitrumAddress, contractAddress, arbusdcAmount); + await sendErc20(globalLogger, 'Arbitrum', arbitrumAddress, contractAddress, arbusdcAmount); } await runWithTimeoutAndExit(main(), 20); diff --git a/bouncer/commands/send_btc.ts b/bouncer/commands/send_btc.ts index 48a6e4a2e6..aaedbc7f21 100755 --- a/bouncer/commands/send_btc.ts +++ b/bouncer/commands/send_btc.ts @@ -1,12 +1,13 @@ #!/usr/bin/env -S pnpm tsx import { sendBtc } from '../shared/send_btc'; +import { globalLogger } from '../shared/utils/logger'; const bitcoinAddress = process.argv[2]; const btcAmount = parseFloat(process.argv[3]); async function sendBitcoin() { try { - await sendBtc(bitcoinAddress, btcAmount); + await sendBtc(globalLogger, bitcoinAddress, btcAmount); process.exit(0); } catch (error) { console.log(`ERROR: ${error}`); diff --git a/bouncer/commands/send_eth.ts b/bouncer/commands/send_eth.ts index a132fb5c2f..833e92bb3b 100755 --- a/bouncer/commands/send_eth.ts +++ b/bouncer/commands/send_eth.ts @@ -10,13 +10,14 @@ import { runWithTimeoutAndExit } from '../shared/utils'; import { sendEvmNative } from '../shared/send_evm'; +import { globalLogger } from '../shared/utils/logger'; async function main() { const ethereumAddress = process.argv[2]; const ethAmount = process.argv[3].trim(); - console.log('Transferring ' + ethAmount + ' Eth to ' + ethereumAddress); - await sendEvmNative('Ethereum', ethereumAddress, ethAmount); + globalLogger.info(`Transferring ${ethAmount} Eth to ${ethereumAddress}`); + await sendEvmNative(globalLogger, 'Ethereum', ethereumAddress, ethAmount); } await runWithTimeoutAndExit(main(), 20); diff --git a/bouncer/commands/send_flip.ts b/bouncer/commands/send_flip.ts index e1e03fe576..8da9b1d1d2 100755 --- a/bouncer/commands/send_flip.ts +++ b/bouncer/commands/send_flip.ts @@ -10,13 +10,14 @@ import { runWithTimeoutAndExit, getContractAddress } from '../shared/utils'; import { sendErc20 } from '../shared/send_erc20'; +import { globalLogger } from '../shared/utils/logger'; async function main(): Promise { const ethereumAddress = process.argv[2]; const flipAmount = process.argv[3].trim(); const contractAddress = getContractAddress('Ethereum', 'Flip'); - await sendErc20('Ethereum', ethereumAddress, contractAddress, flipAmount); + await sendErc20(globalLogger, 'Ethereum', ethereumAddress, contractAddress, flipAmount); } await runWithTimeoutAndExit(main(), 50); diff --git a/bouncer/commands/send_sol.ts b/bouncer/commands/send_sol.ts index fbce63a63e..d3eaac3cd3 100755 --- a/bouncer/commands/send_sol.ts +++ b/bouncer/commands/send_sol.ts @@ -12,13 +12,14 @@ import { runWithTimeoutAndExit } from '../shared/utils'; import { sendSol } from '../shared/send_sol'; +import { globalLogger } from '../shared/utils/logger'; async function main() { const solanaAddress = process.argv[2]; const solAmount = process.argv[3].trim(); - console.log('Transferring ' + solAmount + ' Sol to ' + solanaAddress); - await sendSol(solanaAddress, solAmount); + globalLogger.info(`Transferring ${solAmount} Sol to ${solanaAddress}`); + await sendSol(globalLogger, solanaAddress, solAmount); } await runWithTimeoutAndExit(main(), 20); diff --git a/bouncer/commands/send_solusdc.ts b/bouncer/commands/send_solusdc.ts index c20b35434c..af4450bbed 100755 --- a/bouncer/commands/send_solusdc.ts +++ b/bouncer/commands/send_solusdc.ts @@ -13,13 +13,14 @@ import { runWithTimeoutAndExit } from '../shared/utils'; import { sendSolUsdc } from '../shared/send_solusdc'; +import { globalLogger } from '../shared/utils/logger'; async function main() { const solanaAddress = process.argv[2]; const usdcAmount = process.argv[3].trim(); console.log('Transferring ' + usdcAmount + ' SolUsdc to the ATA of ' + solanaAddress); - await sendSolUsdc(solanaAddress, usdcAmount); + await sendSolUsdc(globalLogger, solanaAddress, usdcAmount); } await runWithTimeoutAndExit(main(), 20); diff --git a/bouncer/commands/send_usdc.ts b/bouncer/commands/send_usdc.ts index 1e2ef88373..765dea01a6 100755 --- a/bouncer/commands/send_usdc.ts +++ b/bouncer/commands/send_usdc.ts @@ -10,13 +10,14 @@ import { runWithTimeoutAndExit, getContractAddress } from '../shared/utils'; import { sendErc20 } from '../shared/send_erc20'; +import { globalLogger } from '../shared/utils/logger'; async function main(): Promise { const ethereumAddress = process.argv[2]; const usdcAmount = process.argv[3].trim(); const contractAddress = getContractAddress('Ethereum', 'Usdc'); - await sendErc20('Ethereum', ethereumAddress, contractAddress, usdcAmount); + await sendErc20(globalLogger, 'Ethereum', ethereumAddress, contractAddress, usdcAmount); } await runWithTimeoutAndExit(main(), 20); diff --git a/bouncer/commands/send_usdt.ts b/bouncer/commands/send_usdt.ts index 3bfed101ee..098159e21a 100755 --- a/bouncer/commands/send_usdt.ts +++ b/bouncer/commands/send_usdt.ts @@ -10,13 +10,14 @@ import { runWithTimeoutAndExit, getContractAddress } from '../shared/utils'; import { sendErc20 } from '../shared/send_erc20'; +import { globalLogger } from '../shared/utils/logger'; async function main(): Promise { const ethereumAddress = process.argv[2]; const usdtAmount = process.argv[3].trim(); const contractAddress = getContractAddress('Ethereum', 'Usdt'); - await sendErc20('Ethereum', ethereumAddress, contractAddress, usdtAmount); + await sendErc20(globalLogger, 'Ethereum', ethereumAddress, contractAddress, usdtAmount); } await runWithTimeoutAndExit(main(), 20); diff --git a/bouncer/commands/set_minimum_deposit.ts b/bouncer/commands/set_minimum_deposit.ts index 964327e901..3a7044da28 100755 --- a/bouncer/commands/set_minimum_deposit.ts +++ b/bouncer/commands/set_minimum_deposit.ts @@ -11,11 +11,12 @@ import { runWithTimeoutAndExit, parseAssetString, amountToFineAmountBigInt } from '../shared/utils'; import { setMinimumDeposit } from '../shared/set_minimum_deposit'; +import { globalLogger } from '../shared/utils/logger'; async function main() { const asset = parseAssetString(process.argv[2]); const amount = amountToFineAmountBigInt(process.argv[3].trim(), asset); - await setMinimumDeposit(asset, amount); + await setMinimumDeposit(globalLogger, asset, amount); } await runWithTimeoutAndExit(main(), 120); diff --git a/bouncer/commands/setup_boost_pools.ts b/bouncer/commands/setup_boost_pools.ts index efa446b215..9b124eeb2e 100755 --- a/bouncer/commands/setup_boost_pools.ts +++ b/bouncer/commands/setup_boost_pools.ts @@ -6,5 +6,6 @@ import { setupBoostPools } from '../shared/setup_boost_pools'; import { runWithTimeoutAndExit } from '../shared/utils'; +import { globalLogger } from '../shared/utils/logger'; -await runWithTimeoutAndExit(setupBoostPools(), 120); +await runWithTimeoutAndExit(setupBoostPools(globalLogger), 120); diff --git a/bouncer/commands/setup_concurrent.ts b/bouncer/commands/setup_concurrent.ts index 69de1e80a8..e66c99b6f6 100755 --- a/bouncer/commands/setup_concurrent.ts +++ b/bouncer/commands/setup_concurrent.ts @@ -8,11 +8,12 @@ import { setupBoostPools } from '../shared/setup_boost_pools'; import { setupSwaps } from '../shared/setup_swaps'; import { runWithTimeoutAndExit } from '../shared/utils'; +import { globalLogger } from '../shared/utils/logger'; async function main(): Promise { - console.log('=== Setup concurrent ==='); - await Promise.all([setupSwaps(), setupBoostPools()]); - console.log('=== Setup concurrent complete ==='); + globalLogger.info('Setup concurrent'); + await Promise.all([setupSwaps(globalLogger), setupBoostPools(globalLogger)]); + globalLogger.info('Setup concurrent complete'); } await runWithTimeoutAndExit(main(), 240); diff --git a/bouncer/commands/setup_lp_account.ts b/bouncer/commands/setup_lp_account.ts index bb27a5c489..fbbe8d9288 100755 --- a/bouncer/commands/setup_lp_account.ts +++ b/bouncer/commands/setup_lp_account.ts @@ -8,13 +8,14 @@ import { runWithTimeoutAndExit } from '../shared/utils'; import { setupLpAccount } from '../shared/setup_account'; +import { globalLogger } from '../shared/utils/logger'; async function main() { const lpKey = process.argv[2]; if (!lpKey) { throw new Error('No LP key provided'); } - await setupLpAccount(lpKey); + await setupLpAccount(globalLogger, lpKey); } await runWithTimeoutAndExit(main(), 120); diff --git a/bouncer/commands/setup_swaps.ts b/bouncer/commands/setup_swaps.ts index a9486eec46..f677f13c22 100755 --- a/bouncer/commands/setup_swaps.ts +++ b/bouncer/commands/setup_swaps.ts @@ -7,5 +7,6 @@ import { setupSwaps } from '../shared/setup_swaps'; import { runWithTimeoutAndExit } from '../shared/utils'; +import { globalLogger } from '../shared/utils/logger'; -await runWithTimeoutAndExit(setupSwaps(), 240); +await runWithTimeoutAndExit(setupSwaps(globalLogger), 240); diff --git a/bouncer/commands/setup_vaults.ts b/bouncer/commands/setup_vaults.ts index 6febfdd4ed..138c237ae2 100755 --- a/bouncer/commands/setup_vaults.ts +++ b/bouncer/commands/setup_vaults.ts @@ -23,9 +23,11 @@ import { initializeSolanaChain, initializeSolanaPrograms, } from '../shared/initialize_new_chains'; +import { globalLogger, loggerChild } from '../shared/utils/logger'; import { getPolkadotApi, observeEvent } from '../shared/utils/substrate'; async function main(): Promise { + const logger = loggerChild(globalLogger, 'setup_vaults'); const btcClient = getBtcClient(); const arbClient = new Web3(getEvmEndpoint('Arbitrum')); const alice = await aliceKeyringPair(); @@ -33,30 +35,42 @@ async function main(): Promise { await using polkadot = await getPolkadotApi(); - console.log('=== Performing initial Vault setup ==='); + logger.info('Performing initial Vault setup'); // Step 1 - await initializeArbitrumChain(); - await initializeSolanaChain(); + await initializeArbitrumChain(logger); + await initializeSolanaChain(logger); // Step 2 - console.log('Forcing rotation'); + logger.info('Forcing rotation'); await submitGovernanceExtrinsic((api) => api.tx.validator.forceRotation()); // Step 3 - console.log('Waiting for new keys'); - - const dotActivationRequest = observeEvent('polkadotVault:AwaitingGovernanceActivation').event; - const btcActivationRequest = observeEvent('bitcoinVault:AwaitingGovernanceActivation').event; - const arbActivationRequest = observeEvent('arbitrumVault:AwaitingGovernanceActivation').event; - const solActivationRequest = observeEvent('solanaVault:AwaitingGovernanceActivation').event; + logger.info('Waiting for new keys'); + + const dotActivationRequest = observeEvent( + logger, + 'polkadotVault:AwaitingGovernanceActivation', + ).event; + const btcActivationRequest = observeEvent( + logger, + 'bitcoinVault:AwaitingGovernanceActivation', + ).event; + const arbActivationRequest = observeEvent( + logger, + 'arbitrumVault:AwaitingGovernanceActivation', + ).event; + const solActivationRequest = observeEvent( + logger, + 'solanaVault:AwaitingGovernanceActivation', + ).event; const dotKey = (await dotActivationRequest).data.newPublicKey; const btcKey = (await btcActivationRequest).data.newPublicKey; const arbKey = (await arbActivationRequest).data.newPublicKey; const solKey = (await solActivationRequest).data.newPublicKey; // Step 4 - console.log('Requesting Polkadot Vault creation'); + logger.info('Requesting Polkadot Vault creation'); const createPolkadotVault = async () => { const { promise, resolve } = deferredPromise<{ vaultAddress: AddressOrPair; @@ -70,7 +84,7 @@ async function main(): Promise { handleSubstrateError(polkadot)(result); } if (result.isInBlock) { - console.log('Polkadot Vault created'); + logger.info('Polkadot Vault created'); // TODO: figure out type inference so we don't have to coerce using `any` const pureCreated = result.findRecord('proxy', 'PureCreated')!; resolve({ @@ -85,10 +99,10 @@ async function main(): Promise { }; const { vaultAddress, vaultExtrinsicIndex } = await createPolkadotVault(); - const proxyAdded = observeEvent('proxy:ProxyAdded', { chain: 'polkadot' }).event; + const proxyAdded = observeEvent(logger, 'proxy:ProxyAdded', { chain: 'polkadot' }).event; // Step 5 - console.log('Rotating Proxy and Funding Accounts.'); + logger.info('Rotating Proxy and Funding Accounts.'); const rotateAndFund = async () => { const { promise, resolve } = deferredPromise(); const rotation = polkadot.tx.proxy.proxy( @@ -131,15 +145,15 @@ async function main(): Promise { const vaultBlockNumber = (await proxyAdded).block; // Step 6 - console.log('Inserting Arbitrum key in the contracts'); - await initializeArbitrumContracts(arbClient, arbKey); + logger.info('Inserting Arbitrum key in the contracts'); + await initializeArbitrumContracts(logger, arbClient, arbKey); // Using arbitrary key for now, we will use solKey generated by SC - console.log('Inserting Solana key in the programs'); - await initializeSolanaPrograms(solClient, solKey); + logger.info('Inserting Solana key in the programs'); + await initializeSolanaPrograms(logger, solClient, solKey); // Step 7 - console.log('Registering Vaults with state chain'); + logger.info('Registering Vaults with state chain'); await submitGovernanceExtrinsic((chainflip) => chainflip.tx.environment.witnessPolkadotVaultCreation(vaultAddress, { blockNumber: vaultBlockNumber, @@ -162,11 +176,11 @@ async function main(): Promise { ); // Confirmation - console.log('Waiting for new epoch...'); - await observeEvent('validator:NewEpoch').event; + logger.info('Waiting for new epoch...'); + await observeEvent(logger, 'validator:NewEpoch').event; - console.log('=== New Epoch ==='); - console.log('=== Vault Setup completed ==='); + logger.info('New Epoch'); + logger.info('Vault Setup completed'); process.exit(0); } diff --git a/bouncer/commands/simple_runtime_upgrade.ts b/bouncer/commands/simple_runtime_upgrade.ts index e5dcdf5569..06aecd3255 100755 --- a/bouncer/commands/simple_runtime_upgrade.ts +++ b/bouncer/commands/simple_runtime_upgrade.ts @@ -10,9 +10,10 @@ import path from 'path'; import { simpleRuntimeUpgrade } from '../shared/simple_runtime_upgrade'; import { runWithTimeoutAndExit } from '../shared/utils'; +import { globalLogger } from '../shared/utils/logger'; async function main(): Promise { - await simpleRuntimeUpgrade(path.dirname(process.cwd())); + await simpleRuntimeUpgrade(globalLogger, path.dirname(process.cwd())); } // 15 minute timeout. We need to wait for user input, compile, and potentially run tests. This is deliberately quite long. diff --git a/bouncer/commands/spam_sol.ts b/bouncer/commands/spam_sol.ts index db29fe6553..84caa08b1e 100755 --- a/bouncer/commands/spam_sol.ts +++ b/bouncer/commands/spam_sol.ts @@ -15,6 +15,7 @@ import BigNumber from 'bignumber.js'; import { sendSol } from '../shared/send_sol'; import { assetDecimals, runWithTimeoutAndExit } from '../shared/utils'; import { sendSolUsdc } from '../shared/send_solusdc'; +import { globalLogger, globalLogger as logger } from '../shared/utils/logger'; async function main() { const asset = process.argv[2].trim() as 'Sol' | 'SolUsdc'; @@ -22,17 +23,7 @@ async function main() { let solAmount = new BigNumber(process.argv[4].trim()); const numberOfDeposits = Number(process.argv[5].trim()); - console.log( - 'Transferring ' + - solAmount + - ' ' + - asset + - ' to ' + - solanaAddress + - ' ' + - numberOfDeposits + - ' times', - ); + logger.info(`Transferring ${solAmount} ${asset} to ${solanaAddress} ${numberOfDeposits} times`); const txPromises = []; const decimals = assetDecimals(asset); @@ -43,10 +34,10 @@ async function main() { solAmount = solAmount.plus(new BigNumber(1).div(10 ** decimals)); switch (asset) { case 'Sol': - txPromises.push(sendSol(solanaAddress, solAmount.toString(), false)); + txPromises.push(sendSol(globalLogger, solanaAddress, solAmount.toString())); break; case 'SolUsdc': - txPromises.push(sendSolUsdc(solanaAddress, solAmount.toString(), false)); + txPromises.push(sendSolUsdc(globalLogger, solanaAddress, solAmount.toString())); break; default: throw new Error('Unsupported asset'); @@ -54,7 +45,7 @@ async function main() { } const txs = await Promise.all(txPromises); - txs.forEach((tx) => console.log('tx: ', tx?.transaction?.signatures[0])); + txs.forEach((tx) => logger.info('tx: ', tx?.transaction?.signatures[0])); } await runWithTimeoutAndExit(main(), 10); diff --git a/bouncer/commands/stop_boosting.ts b/bouncer/commands/stop_boosting.ts index cdc816e000..b3e633dccd 100755 --- a/bouncer/commands/stop_boosting.ts +++ b/bouncer/commands/stop_boosting.ts @@ -12,15 +12,17 @@ import { InternalAsset as Asset } from '@chainflip/cli'; import { runWithTimeoutAndExit } from '../shared/utils'; import { stopBoosting } from '../tests/boost'; +import { globalLogger } from '../shared/utils/logger'; async function main(): Promise { const event = await stopBoosting( + globalLogger, process.argv[2] as Asset, Number(process.argv[3]), process.argv[4], true, ); - console.log(`Stopped boosting event: ${JSON.stringify(event)}`); + globalLogger.info(`Stopped boosting event: ${JSON.stringify(event)}`); } await runWithTimeoutAndExit(main(), 30); diff --git a/bouncer/commands/submit_runtime_upgrade.ts b/bouncer/commands/submit_runtime_upgrade.ts index 0435425460..463e78bd35 100755 --- a/bouncer/commands/submit_runtime_upgrade.ts +++ b/bouncer/commands/submit_runtime_upgrade.ts @@ -11,6 +11,7 @@ import { submitRuntimeUpgradeWithRestrictions } from '../shared/submit_runtime_upgrade'; import { runWithTimeoutAndExit } from '../shared/utils'; +import { globalLogger } from '../shared/utils/logger'; async function main() { const wasmPath = process.argv[2]; @@ -21,7 +22,12 @@ async function main() { const arg4 = process.argv[4].trim(); const percentNodesUpgraded = arg4 ? Number(arg4) : undefined; - await submitRuntimeUpgradeWithRestrictions(wasmPath, semverRestriction, percentNodesUpgraded); + await submitRuntimeUpgradeWithRestrictions( + globalLogger, + wasmPath, + semverRestriction, + percentNodesUpgraded, + ); } await runWithTimeoutAndExit(main(), 20); diff --git a/bouncer/shared/approve_erc20.ts b/bouncer/shared/approve_erc20.ts index 93b4fb2c1e..fc1ddf0e67 100644 --- a/bouncer/shared/approve_erc20.ts +++ b/bouncer/shared/approve_erc20.ts @@ -4,10 +4,16 @@ import { amountToFineAmount, chainFromAsset, getEvmEndpoint } from '../shared/ut import { getContractAddress } from './utils'; import { signAndSendTxEvm } from './send_evm'; import { getErc20abi } from './contract_interfaces'; +import { Logger } from './utils/logger'; const erc20abi = await getErc20abi(); -export async function approveErc20(asset: Asset, toAddress: string, amount: string) { +export async function approveErc20( + logger: Logger, + asset: Asset, + toAddress: string, + amount: string, +) { const chain = chainFromAsset(asset); const web3 = new Web3(getEvmEndpoint(chain)); @@ -21,7 +27,7 @@ export async function approveErc20(asset: Asset, toAddress: string, amount: stri const txData = tokenContract.methods.approve(toAddress, tokenAmount).encodeABI(); - console.log('Approving ' + amount + ' ' + asset + ' to ' + toAddress); + logger.debug('Approving ' + amount + ' ' + asset + ' to ' + toAddress); - await signAndSendTxEvm(chain, tokenContractAddress, '0', txData); + await signAndSendTxEvm(logger, chain, tokenContractAddress, '0', txData); } diff --git a/bouncer/shared/btc_vault_swap.ts b/bouncer/shared/btc_vault_swap.ts index 6c653e9712..531964e056 100644 --- a/bouncer/shared/btc_vault_swap.ts +++ b/bouncer/shared/btc_vault_swap.ts @@ -14,6 +14,7 @@ import { } from '../shared/utils'; import { getChainflipApi, observeEvent } from '../shared/utils/substrate'; import { fundFlip } from '../shared/fund_flip'; +import { Logger } from './utils/logger'; interface BtcVaultSwapDetails { chain: string; @@ -28,6 +29,7 @@ interface BtcVaultSwapExtraParameters { } export async function buildAndSendBtcVaultSwap( + logger: Logger, depositAmountBtc: number, destinationAsset: Asset, destinationAddress: string, @@ -49,6 +51,7 @@ export async function buildAndSendBtcVaultSwap( retry_duration: 0, }; + logger.trace('Requesting vault swap parameter encoding'); const BtcVaultSwapDetails = (await chainflip.rpc( `cf_request_swap_parameter_encoding`, brokerFees.account, @@ -67,18 +70,19 @@ export async function buildAndSendBtcVaultSwap( assert.strictEqual(BtcVaultSwapDetails.chain, 'Bitcoin'); + logger.trace('Sending BTC vault swap transaction'); const txid = await sendVaultTransaction( BtcVaultSwapDetails.nulldata_payload, depositAmountBtc, BtcVaultSwapDetails.deposit_address, refundAddress, ); - await waitForBtcTransaction(txid); + await waitForBtcTransaction(logger, txid); return txid; } -export async function openPrivateBtcChannel(brokerUri: string): Promise { +export async function openPrivateBtcChannel(logger: Logger, brokerUri: string): Promise { // Check if the channel is already open const chainflip = await getChainflipApi(); const broker = createStateChainKeypair(brokerUri); @@ -96,12 +100,13 @@ export async function openPrivateBtcChannel(brokerUri: string): Promise (await chainflip.query.swapping.brokerBond()) as any as string, assetDecimals('Flip'), ); - await fundFlip(broker.address, fundAmount); + await fundFlip(logger, broker.address, fundAmount); // Open the private channel - const openedChannelEvent = observeEvent('swapping:PrivateBrokerChannelOpened', { + const openedChannelEvent = observeEvent(logger, 'swapping:PrivateBrokerChannelOpened', { test: (event) => event.data.brokerId === broker.address, }).event; + logger.trace('Opening private BTC channel'); await brokerMutex.runExclusive(async () => { await chainflip.tx.swapping .openPrivateBtcChannel() @@ -110,14 +115,19 @@ export async function openPrivateBtcChannel(brokerUri: string): Promise return Number((await openedChannelEvent).data.channelId); } -export async function registerAffiliate(brokerUri: string, withdrawalAddress: string) { +export async function registerAffiliate( + logger: Logger, + brokerUri: string, + withdrawalAddress: string, +) { const chainflip = await getChainflipApi(); const broker = createStateChainKeypair(brokerUri); - const registeredEvent = observeEvent('swapping:AffiliateRegistration', { + const registeredEvent = observeEvent(logger, 'swapping:AffiliateRegistration', { test: (event) => event.data.brokerId === broker.address, }).event; + logger.trace('Registering affiliate'); await brokerMutex.runExclusive(async () => { await chainflip.tx.swapping .registerAffiliate(withdrawalAddress) diff --git a/bouncer/shared/bump_release_version.ts b/bouncer/shared/bump_release_version.ts index 1e5fcbec43..ec7a806707 100755 --- a/bouncer/shared/bump_release_version.ts +++ b/bouncer/shared/bump_release_version.ts @@ -1,14 +1,17 @@ import { execSync } from 'child_process'; +import { globalLogger } from './utils/logger'; export type SemVerLevel = 'major' | 'minor' | 'patch'; // Bumps the version of all the packages in the workspace by the specified level. export async function bumpReleaseVersion(level: SemVerLevel, projectRoot: string) { - console.log(`Bumping the version of all packages in the workspace by ${level}...`); + globalLogger.info(`Bumping the version of all packages in the workspace by ${level}...`); try { execSync(`cd ${projectRoot} && cargo ws version ${level} --no-git-commit -y`); } catch (error) { - console.log(error); - console.log('Ensure you have cargo workspaces installed: `cargo install cargo-workspaces`'); + globalLogger.error(error); + globalLogger.warn( + 'Ensure you have cargo workspaces installed: `cargo install cargo-workspaces`', + ); } } diff --git a/bouncer/shared/create_lp_pool.ts b/bouncer/shared/create_lp_pool.ts index 94eb85ed6c..092bc37103 100644 --- a/bouncer/shared/create_lp_pool.ts +++ b/bouncer/shared/create_lp_pool.ts @@ -1,8 +1,9 @@ import { Asset, assetPriceToInternalAssetPrice } from '../shared/utils'; import { submitGovernanceExtrinsic } from './cf_governance'; +import { Logger } from './utils/logger'; import { getChainflipApi, observeEvent } from './utils/substrate'; -export async function createLpPool(ccy: Asset, initialPrice: number) { +export async function createLpPool(logger: Logger, ccy: Asset, initialPrice: number) { await using chainflip = await getChainflipApi(); if ( @@ -13,10 +14,10 @@ export async function createLpPool(ccy: Asset, initialPrice: number) { ).toJSON()! === null ) { const price = assetPriceToInternalAssetPrice(ccy, 'Usdc', initialPrice); - console.log( + logger.info( 'Setting up ' + ccy + ' pool with an initial price of ' + initialPrice + ' USDC per ' + ccy, ); - const poolCreatedEvent = observeEvent('liquidityPools:NewPoolCreated', { + const poolCreatedEvent = observeEvent(logger, 'liquidityPools:NewPoolCreated', { test: (event) => event.data.baseAsset === ccy, }).event; await submitGovernanceExtrinsic((api) => api.tx.liquidityPools.newPool(ccy, 'usdc', 20, price)); diff --git a/bouncer/shared/delete_all_orders_lp_api.ts b/bouncer/shared/delete_all_orders_lp_api.ts index 0115483441..f4817d25cb 100644 --- a/bouncer/shared/delete_all_orders_lp_api.ts +++ b/bouncer/shared/delete_all_orders_lp_api.ts @@ -1,81 +1,82 @@ import { lpApiRpc } from './json_rpc'; import { createStateChainKeypair } from './utils'; +import { Logger } from './utils/logger'; import { getChainflipApi } from './utils/substrate'; -export async function DeleteAllOrdersLpApi() { +export async function DeleteAllOrdersLpApi(logger: Logger) { await using chainflip = await getChainflipApi(); const lp = createStateChainKeypair(process.env.LP_URI || '//LP_1'); let orders = await chainflip.rpc('cf_pool_orders', 'BTC', 'USDC', lp.address); - console.log(`BTC pool: ${JSON.stringify(orders)}`); + logger.info(`BTC pool: ${JSON.stringify(orders)}`); orders = await chainflip.rpc('cf_pool_orders', 'ETH', 'USDC', lp.address); - console.log(`ETH pool: ${JSON.stringify(orders)}`); + logger.info(`ETH pool: ${JSON.stringify(orders)}`); orders = await chainflip.rpc('cf_pool_orders', 'DOT', 'USDC', lp.address); - console.log(`DOT pool: ${JSON.stringify(orders)}`); + logger.info(`DOT pool: ${JSON.stringify(orders)}`); orders = await chainflip.rpc( 'cf_pool_orders', { chain: 'Arbitrum', asset: 'ETH' }, 'USDC', lp.address, ); - console.log(`ARBETH pool: ${JSON.stringify(orders)}`); + logger.info(`ARBETH pool: ${JSON.stringify(orders)}`); orders = await chainflip.rpc( 'cf_pool_orders', { chain: 'Arbitrum', asset: 'USDC' }, 'USDC', lp.address, ); - console.log(`ARBUSDC pool: ${JSON.stringify(orders)}`); + logger.info(`ARBUSDC pool: ${JSON.stringify(orders)}`); orders = await chainflip.rpc( 'cf_pool_orders', { chain: 'Ethereum', asset: 'USDT' }, 'USDC', lp.address, ); - console.log(`USDT pool: ${JSON.stringify(orders)}`); + logger.info(`USDT pool: ${JSON.stringify(orders)}`); orders = await chainflip.rpc( 'cf_pool_orders', { chain: 'Ethereum', asset: 'FLIP' }, 'USDC', lp.address, ); - console.log(`FLIP pool: ${JSON.stringify(orders)}`); + logger.info(`FLIP pool: ${JSON.stringify(orders)}`); - await lpApiRpc(`lp_cancel_all_orders`, []); + await lpApiRpc(logger, `lp_cancel_all_orders`, []); orders = await chainflip.rpc('cf_pool_orders', 'BTC', 'USDC', lp.address); - console.log(`BTC pool: ${JSON.stringify(orders)}`); + logger.info(`BTC pool: ${JSON.stringify(orders)}`); orders = await chainflip.rpc('cf_pool_orders', 'ETH', 'USDC', lp.address); - console.log(`ETH pool: ${JSON.stringify(orders)}`); + logger.info(`ETH pool: ${JSON.stringify(orders)}`); orders = await chainflip.rpc('cf_pool_orders', 'DOT', 'USDC', lp.address); - console.log(`DOT pool: ${JSON.stringify(orders)}`); + logger.info(`DOT pool: ${JSON.stringify(orders)}`); orders = await chainflip.rpc( 'cf_pool_orders', { chain: 'Arbitrum', asset: 'ETH' }, 'USDC', lp.address, ); - console.log(`ARBETH pool: ${JSON.stringify(orders)}`); + logger.info(`ARBETH pool: ${JSON.stringify(orders)}`); orders = await chainflip.rpc( 'cf_pool_orders', { chain: 'Arbitrum', asset: 'USDC' }, 'USDC', lp.address, ); - console.log(`ARBUSDC pool: ${JSON.stringify(orders)}`); + logger.info(`ARBUSDC pool: ${JSON.stringify(orders)}`); orders = await chainflip.rpc( 'cf_pool_orders', { chain: 'Ethereum', asset: 'USDT' }, 'USDC', lp.address, ); - console.log(`USDT pool: ${JSON.stringify(orders)}`); + logger.info(`USDT pool: ${JSON.stringify(orders)}`); orders = await chainflip.rpc( 'cf_pool_orders', { chain: 'Ethereum', asset: 'FLIP' }, 'USDC', lp.address, ); - console.log(`FLIP pool: ${JSON.stringify(orders)}`); + logger.info(`FLIP pool: ${JSON.stringify(orders)}`); } diff --git a/bouncer/shared/deposit_liquidity.ts b/bouncer/shared/deposit_liquidity.ts index a08bf5c250..ed5636e8b1 100644 --- a/bouncer/shared/deposit_liquidity.ts +++ b/bouncer/shared/deposit_liquidity.ts @@ -15,8 +15,10 @@ import { } from '../shared/utils'; import { send } from '../shared/send'; import { getChainflipApi, observeEvent } from './utils/substrate'; +import { Logger } from './utils/logger'; export async function depositLiquidity( + logger: Logger, ccy: Asset, amount: number, waitForFinalization = false, @@ -40,7 +42,7 @@ export async function depositLiquidity( refundAddress = chain === 'Dot' ? decodeDotAddressForContract(refundAddress) : refundAddress; refundAddress = chain === 'Sol' ? decodeSolAddress(refundAddress) : refundAddress; - console.log('Registering Liquidity Refund Address for ' + ccy + ': ' + refundAddress); + logger.debug('Registering Liquidity Refund Address for ' + ccy + ': ' + refundAddress); await lpMutex.runExclusive(async () => { await chainflip.tx.liquidityProvider .registerLiquidityRefundAddress({ [chain]: refundAddress }) @@ -48,11 +50,11 @@ export async function depositLiquidity( }); } - let eventHandle = observeEvent('liquidityProvider:LiquidityDepositAddressReady', { + let eventHandle = observeEvent(logger, 'liquidityProvider:LiquidityDepositAddressReady', { test: (event) => event.data.asset === ccy && event.data.accountId === lp.address, }).event; - console.log('Requesting ' + ccy + ' deposit address'); + logger.debug('Requesting ' + ccy + ' deposit address'); await lpMutex.runExclusive(async () => { await chainflip.tx.liquidityProvider .requestLiquidityDepositAddress(ccy, null) @@ -61,9 +63,9 @@ export async function depositLiquidity( const ingressAddress = (await eventHandle).data.depositAddress[chain]; - console.log('Received ' + ccy + ' address: ' + ingressAddress); - console.log('Sending ' + amount + ' ' + ccy + ' to ' + ingressAddress); - eventHandle = observeEvent('assetBalances:AccountCredited', { + logger.debug('Received ' + ccy + ' address: ' + ingressAddress); + logger.debug('Sending ' + amount + ' ' + ccy + ' to ' + ingressAddress); + eventHandle = observeEvent(logger, 'assetBalances:AccountCredited', { test: (event) => event.data.asset === ccy && event.data.accountId === lp.address && @@ -74,7 +76,7 @@ export async function depositLiquidity( finalized: waitForFinalization, }).event; - await send(ccy, ingressAddress, String(amount)); + await send(logger, ccy, ingressAddress, String(amount)); return eventHandle; } diff --git a/bouncer/shared/docker_utils.ts b/bouncer/shared/docker_utils.ts index 244a9052a6..e9a744e44f 100644 --- a/bouncer/shared/docker_utils.ts +++ b/bouncer/shared/docker_utils.ts @@ -1,22 +1,31 @@ import { execSync } from 'node:child_process'; +import { Logger } from './utils/logger'; export function isNetworkConnected(containerName: string, networkName: string): boolean { const res = execSync(`docker inspect ${containerName}`); return JSON.parse(res.toString())[0].NetworkSettings.Networks[networkName] !== undefined; } -export async function disconnectContainerFromNetwork(containerName: string, networkName: string) { +export async function disconnectContainerFromNetwork( + logger: Logger, + containerName: string, + networkName: string, +) { execSync(`docker network disconnect ${networkName} ${containerName}`); if (isNetworkConnected(containerName, networkName)) { throw new Error('Failed to disconnect container from network'); } - console.log(`Disconnected ${containerName} from ${networkName}!`); + logger.info(`Disconnected ${containerName} from ${networkName}!`); } -export async function connectContainerToNetwork(containerName: string, networkName: string) { +export async function connectContainerToNetwork( + logger: Logger, + containerName: string, + networkName: string, +) { execSync(`docker network connect ${networkName} ${containerName}`); if (!isNetworkConnected(containerName, networkName)) { throw new Error('Failed to connect container to network'); } - console.log(`Connected ${containerName} to ${networkName}!`); + logger.info(`Connected ${containerName} to ${networkName}!`); } diff --git a/bouncer/shared/evm_vault_swap.ts b/bouncer/shared/evm_vault_swap.ts index 7aef188b5a..f900e113cc 100644 --- a/bouncer/shared/evm_vault_swap.ts +++ b/bouncer/shared/evm_vault_swap.ts @@ -18,6 +18,7 @@ import { import { CcmDepositMetadata, DcaParams, FillOrKillParamsX128 } from './new_swap'; import { getChainflipApi } from './utils/substrate'; import { ChannelRefundParameters } from './sol_vault_swap'; +import { Logger } from './utils/logger'; const erc20Assets: Asset[] = ['Flip', 'Usdc', 'Usdt', 'ArbUsdc']; @@ -35,6 +36,7 @@ interface EvmVaultSwapExtraParameters { } export async function executeEvmVaultSwap( + logger: Logger, brokerAddress: string, sourceAsset: Asset, destAsset: Asset, @@ -61,7 +63,7 @@ export async function executeEvmVaultSwap( minPriceX128: '0', }; const fineAmount = amountToFineAmount(amountToSwap, assetDecimals(sourceAsset)); - const evmWallet = wallet ?? (await createEvmWalletAndFund(sourceAsset)); + const evmWallet = wallet ?? (await createEvmWalletAndFund(logger, sourceAsset)); if (erc20Assets.includes(sourceAsset)) { // Doing effectively infinite approvals to make sure it doesn't fail. @@ -87,6 +89,7 @@ export async function executeEvmVaultSwap( refund_parameters: refundParams, }; + logger.trace('Requesting vault swap parameter encoding'); const vaultSwapDetails = (await chainflip.rpc( `cf_request_swap_parameter_encoding`, brokerAddress, @@ -119,6 +122,7 @@ export async function executeEvmVaultSwap( gas: srcChain === 'Arbitrum' ? 32000000 : 5000000, }; + logger.trace('Signing and Sending EVM vault swap transaction'); const signedTx = await web3.eth.accounts.signTransaction(tx, evmWallet.privateKey); const receipt = await web3.eth.sendSignedTransaction(signedTx.rawTransaction as string); diff --git a/bouncer/shared/fund_flip.ts b/bouncer/shared/fund_flip.ts index b37571ab3f..81af495300 100644 --- a/bouncer/shared/fund_flip.ts +++ b/bouncer/shared/fund_flip.ts @@ -13,10 +13,12 @@ import { import { amountToFineAmount } from '../shared/utils'; import { approveErc20 } from './approve_erc20'; import { observeEvent } from './utils/substrate'; +import { Logger } from './utils/logger'; -export async function fundFlip(scAddress: string, flipAmount: string) { +export async function fundFlip(logger: Logger, scAddress: string, flipAmount: string) { // Doing effectively infinite approvals to prevent race conditions between tests await approveErc20( + logger, 'Flip', getContractAddress('Ethereum', 'GATEWAY'), '100000000000000000000000000', @@ -29,7 +31,7 @@ export async function fundFlip(scAddress: string, flipAmount: string) { const gatewayContractAddress = getContractAddress('Ethereum', 'GATEWAY'); const whaleKey = getWhaleKey('Ethereum'); - console.log('Approving ' + flipAmount + ' Flip to State Chain Gateway'); + logger.debug('Approving ' + flipAmount + ' Flip to State Chain Gateway'); const wallet = new Wallet(whaleKey, ethers.getDefaultProvider(getEvmEndpoint('Ethereum'))); @@ -43,7 +45,7 @@ export async function fundFlip(scAddress: string, flipAmount: string) { nonce: await getNextEvmNonce('Ethereum'), } as const; - console.log('Funding ' + flipAmount + ' Flip to ' + scAddress); + logger.debug('Funding ' + flipAmount + ' Flip to ' + scAddress); let pubkey = decodeFlipAddressForContract(scAddress); if (pubkey.substr(0, 2) !== '0x') { @@ -56,7 +58,7 @@ export async function fundFlip(scAddress: string, flipAmount: string) { txOptions, ); - console.log( + logger.debug( 'Transaction complete, tx_hash: ' + receipt2.hash + ' blockNumber: ' + @@ -64,7 +66,7 @@ export async function fundFlip(scAddress: string, flipAmount: string) { ' blockHash: ' + receipt2.blockHash, ); - await observeEvent('funding:Funded', { + await observeEvent(logger, 'funding:Funded', { test: (event) => hexPubkeyToFlipAddress(pubkey) === event.data.accountId, }).event; } diff --git a/bouncer/shared/initialize_new_chains.ts b/bouncer/shared/initialize_new_chains.ts index 88d308fb5f..bff9edea63 100644 --- a/bouncer/shared/initialize_new_chains.ts +++ b/bouncer/shared/initialize_new_chains.ts @@ -18,22 +18,24 @@ import { getSolanaVaultIdl, getKeyManagerAbi } from '../shared/contract_interfac import { signAndSendTxEvm } from '../shared/send_evm'; import { submitGovernanceExtrinsic } from './cf_governance'; import { observeEvent } from './utils/substrate'; +import { Logger } from './utils/logger'; -export async function initializeArbitrumChain() { - console.log('Initializing Arbitrum'); - const arbInitializationRequest = observeEvent('arbitrumVault:ChainInitialized').event; +export async function initializeArbitrumChain(logger: Logger) { + logger.info('Initializing Arbitrum'); + const arbInitializationRequest = observeEvent(logger, 'arbitrumVault:ChainInitialized').event; await submitGovernanceExtrinsic((chainflip) => chainflip.tx.arbitrumVault.initializeChain()); await arbInitializationRequest; } -export async function initializeSolanaChain() { - console.log('Initializing Solana'); - const solInitializationRequest = observeEvent('solanaVault:ChainInitialized').event; +export async function initializeSolanaChain(logger: Logger) { + logger.info('Initializing Solana'); + const solInitializationRequest = observeEvent(logger, 'solanaVault:ChainInitialized').event; await submitGovernanceExtrinsic((chainflip) => chainflip.tx.solanaVault.initializeChain()); await solInitializationRequest; } export async function initializeArbitrumContracts( + logger: Logger, arbClient: Web3, arbKey: { pubKeyX: string; pubKeyYParity: string }, ) { @@ -50,7 +52,7 @@ export async function initializeArbitrumContracts( pubKeyYParity: arbKey.pubKeyYParity === 'Odd' ? 1 : 0, }) .encodeABI(); - await signAndSendTxEvm('Arbitrum', keyManagerAddress, '0', txData); + await signAndSendTxEvm(logger, 'Arbitrum', keyManagerAddress, '0', txData); } function numberToBuffer(bytes: number, number: number): Buffer { @@ -71,7 +73,11 @@ function bigNumberToU64Buffer(number: bigint): Buffer { return buf; } -export async function initializeSolanaPrograms(solClient: Connection, solKey: string) { +export async function initializeSolanaPrograms( + logger: Logger, + solClient: Connection, + solKey: string, +) { function createUpgradeAuthorityInstruction( programId: PublicKey, upgradeAuthority: PublicKey, @@ -125,8 +131,8 @@ export async function initializeSolanaPrograms(solClient: Connection, solKey: st const upgradeSignerPda = new PublicKey('H7G2avdmRSQyVxPcgZJPGXVCPhC61TMAKdvYBRF42zJ9'); // Fund new Solana Agg key - console.log('Funding Solana new aggregate key:', newAggKey.toString()); - await sendSol(solKey, '100'); + logger.info('Funding Solana new aggregate key:', newAggKey.toString()); + await sendSol(logger, solKey, '100'); // Initialize Vault program let tx = new Transaction().add( @@ -156,7 +162,7 @@ export async function initializeSolanaPrograms(solClient: Connection, solKey: st programId: solanaVaultProgramId, }), ); - await signAndSendTxSol(tx); + await signAndSendTxSol(logger, tx); // Set nonce authority to the new AggKey tx = new Transaction(); @@ -180,7 +186,7 @@ export async function initializeSolanaPrograms(solClient: Connection, solKey: st }), ); } - await signAndSendTxSol(tx); + await signAndSendTxSol(logger, tx); // Set Vault's upgrade authority to upgradeSignerPda and enable token support tx = new Transaction().add( @@ -219,7 +225,7 @@ export async function initializeSolanaPrograms(solClient: Connection, solKey: st programId: solanaVaultProgramId, }), ); - await signAndSendTxSol(tx); + await signAndSendTxSol(logger, tx); // Set Governance authority to the new AggKey (State Chain) const setGovKeyWithGovKeyDiscriminatorString = vaultIdl.instructions.find( @@ -241,5 +247,5 @@ export async function initializeSolanaPrograms(solClient: Connection, solKey: st programId: solanaVaultProgramId, }), ); - await signAndSendTxSol(tx); + await signAndSendTxSol(logger, tx); } diff --git a/bouncer/shared/json_rpc.ts b/bouncer/shared/json_rpc.ts index fe54365805..cdbac52d04 100644 --- a/bouncer/shared/json_rpc.ts +++ b/bouncer/shared/json_rpc.ts @@ -1,11 +1,14 @@ +import { Logger, throwError } from './utils/logger'; + let id = 0; export async function jsonRpc( + logger: Logger, method: string, // eslint-disable-next-line @typescript-eslint/no-explicit-any params: any[], endpoint?: string, ): Promise { - console.log('Sending json RPC', method); + logger.debug('Sending json RPC', method); id++; const request = JSON.stringify({ @@ -27,19 +30,18 @@ export async function jsonRpc( const data = await response.json(); if (data.error) { - throw new Error(`JSON Rpc request ${request} failed: ${data.error.message}`); - } else { - return data.result; + throwError(logger, new Error(`JSON Rpc request ${request} failed: ${data.error.message}`)); } + return data.result; } // eslint-disable-next-line @typescript-eslint/no-explicit-any -export async function lpApiRpc(method: string, params: any[]): Promise { +export async function lpApiRpc(logger: Logger, method: string, params: any[]): Promise { // The port for the lp api is defined in `chainflip-lp-api.service` - return jsonRpc(method, params, 'http://127.0.0.1:10589'); + return jsonRpc(logger, method, params, 'http://127.0.0.1:10589'); } // eslint-disable-next-line @typescript-eslint/no-explicit-any -export async function brokerApiRpc(method: string, params: any[]): Promise { - return jsonRpc(method, params, 'http://127.0.0.1:10997'); +export async function brokerApiRpc(logger: Logger, method: string, params: any[]): Promise { + return jsonRpc(logger, method, params, 'http://127.0.0.1:10997'); } diff --git a/bouncer/shared/limit_order.ts b/bouncer/shared/limit_order.ts index dd82a908ba..e4e8f9677e 100644 --- a/bouncer/shared/limit_order.ts +++ b/bouncer/shared/limit_order.ts @@ -7,8 +7,10 @@ import { createStateChainKeypair, } from '../shared/utils'; import { getChainflipApi, observeEvent } from './utils/substrate'; +import { Logger } from './utils/logger'; export async function limitOrder( + logger: Logger, ccy: Asset, amount: number, orderId: number, @@ -20,8 +22,8 @@ export async function limitOrder( const lp = createStateChainKeypair(lpKey ?? (process.env.LP_URI || '//LP_1')); - console.log('Setting up ' + ccy + ' limit order'); - const orderCreatedEvent = observeEvent('liquidityPools:LimitOrderUpdated', { + logger.debug('Setting up ' + ccy + ' limit order'); + const orderCreatedEvent = observeEvent(logger, 'liquidityPools:LimitOrderUpdated', { test: (event) => event.data.lp === lp.address && event.data.baseAsset === ccy && event.data.id === String(0), }).event; diff --git a/bouncer/shared/new_btc_address.ts b/bouncer/shared/new_btc_address.ts index be33033d2b..88c224ab68 100644 --- a/bouncer/shared/new_btc_address.ts +++ b/bouncer/shared/new_btc_address.ts @@ -61,14 +61,8 @@ export async function newBtcAddress(seed: string, type: BtcAddressType): Promise params: ['addr(' + address + ')'], }; - let walletDescriptor; - try { - walletDescriptor = (await axios.post(btcEndpoint, getDescriptorData, axiosConfig)).data.result - .descriptor; - } catch (err) { - console.log(err); - process.exit(-1); - } + const walletDescriptor = (await axios.post(btcEndpoint, getDescriptorData, axiosConfig)).data + .result.descriptor; const registerAddressData = { jsonrpc: '1.0', diff --git a/bouncer/shared/new_swap.ts b/bouncer/shared/new_swap.ts index 0919ddd0a4..e18acd9dc6 100644 --- a/bouncer/shared/new_swap.ts +++ b/bouncer/shared/new_swap.ts @@ -1,5 +1,6 @@ import { InternalAsset as Asset, Chain, Asset as SCAsset, broker } from '@chainflip/cli'; import { decodeDotAddressForContract, chainFromAsset, stateChainAssetFromAsset } from './utils'; +import { Logger } from './utils/logger'; const defaultCommissionBps = 100; // 1% @@ -10,6 +11,7 @@ export type FillOrKillParamsX128 = NonNullable; export async function newSwap( + logger: Logger, sourceAsset: Asset, destAsset: Asset, destAddress: string, @@ -53,7 +55,7 @@ export async function newSwap( break; // Exit the loop on success } catch (error) { retryCount++; - console.error( + logger.error( `Request swap deposit address for ${sourceAsset} attempt: ${retryCount} failed: ${error}`, ); } diff --git a/bouncer/shared/perform_swap.ts b/bouncer/shared/perform_swap.ts index 4b21136a35..1a0ee49291 100644 --- a/bouncer/shared/perform_swap.ts +++ b/bouncer/shared/perform_swap.ts @@ -32,6 +32,7 @@ import { getChainflipApi, observeEvent } from './utils/substrate'; import { executeEvmVaultSwap } from './evm_vault_swap'; import { executeSolVaultSwap } from './sol_vault_swap'; import { buildAndSendBtcVaultSwap } from './btc_vault_swap'; +import { Logger, throwError } from './utils/logger'; function encodeDestinationAddress(address: string, destAsset: Asset): string { let destAddress = address; @@ -54,18 +55,17 @@ export type SwapParams = { }; export async function requestNewSwap( + logger: Logger, sourceAsset: Asset, destAsset: Asset, destAddress: string, - tag = '', messageMetadata?: CcmDepositMetadata, brokerCommissionBps?: number, - log = true, boostFeeBps = 0, fillOrKillParams?: FillOrKillParamsX128, dcaParams?: DcaParams, ): Promise { - const addressPromise = observeEvent('swapping:SwapDepositAddressReady', { + const addressPromise = observeEvent(logger, 'swapping:SwapDepositAddressReady', { test: (event) => { // Find deposit address for the right swap by looking at destination address: const destAddressEvent = encodeDestinationAddress( @@ -94,6 +94,7 @@ export async function requestNewSwap( }).event; await newSwap( + logger, sourceAsset, destAsset, destAddress, @@ -110,10 +111,8 @@ export async function requestNewSwap( const channelDestAddress = res.destinationAddress[shortChainFromAsset(destAsset)]; const channelId = Number(res.channelId.replaceAll(',', '')); - if (log) { - console.log(`${tag} Deposit address: ${depositAddress}`); - console.log(`${tag} Destination address is: ${channelDestAddress} Channel ID is: ${channelId}`); - } + logger.debug(`$Deposit address: ${depositAddress}`); + logger.debug(`Destination address is: ${channelDestAddress} Channel ID is: ${channelId}`); return { sourceAsset, @@ -129,20 +128,21 @@ export enum SenderType { Vault, } +// Note: if using the swap context, the logger must contain the tag export async function doPerformSwap( + logger: Logger, { sourceAsset, destAsset, destAddress, depositAddress, channelId }: SwapParams, - tag = '', messageMetadata?: CcmDepositMetadata, senderType = SenderType.Address, amount?: string, - log = true, swapContext?: SwapContext, ) { const oldBalance = await getBalance(destAsset, destAddress); - if (log) console.log(`${tag} Old balance: ${oldBalance}`); + logger.trace(`Old balance: ${oldBalance}`); const swapRequestedHandle = observeSwapRequested( + logger, sourceAsset, destAsset, { type: TransactionOrigin.DepositChannel, channelId }, @@ -154,103 +154,103 @@ export async function doPerformSwap( : Promise.resolve(); await (senderType === SenderType.Address - ? send(sourceAsset, depositAddress, amount, log) - : sendViaCfTester(sourceAsset, depositAddress)); + ? send(logger, sourceAsset, depositAddress, amount) + : sendViaCfTester(logger, sourceAsset, depositAddress)); - if (log) console.log(`${tag} Funded the address`); + logger.trace(`Funded the address`); - swapContext?.updateStatus(tag, SwapStatus.Funded); + swapContext?.updateStatus(logger, SwapStatus.Funded); await swapRequestedHandle; - swapContext?.updateStatus(tag, SwapStatus.SwapScheduled); + swapContext?.updateStatus(logger, SwapStatus.SwapScheduled); - if (log) console.log(`${tag} Waiting for balance to update`); + logger.trace(`Waiting for balance to update`); try { const [newBalance] = await Promise.all([ - observeBalanceIncrease(destAsset, destAddress, oldBalance), + observeBalanceIncrease(logger, destAsset, destAddress, oldBalance), ccmEventEmitted, ]); const chain = chainFromAsset(sourceAsset); if (chain !== 'Bitcoin' && chain !== 'Polkadot') { - if (log) console.log(`${tag} Waiting deposit fetch ${depositAddress}`); + logger.trace(`Waiting deposit fetch ${depositAddress}`); await observeFetch(sourceAsset, depositAddress); } - if (log) console.log(`${tag} Swap success! New balance: ${newBalance}!`); - swapContext?.updateStatus(tag, SwapStatus.Success); + logger.trace(`Swap success! New balance: ${newBalance}!`); + swapContext?.updateStatus(logger, SwapStatus.Success); } catch (err) { - swapContext?.updateStatus(tag, SwapStatus.Failure); - throw new Error(`${tag} ${err}`); + swapContext?.updateStatus(logger, SwapStatus.Failure); + throwError(logger, new Error(`$${err}`)); } } +// Note: if using the swap context, the logger must contain the tag export async function performSwap( + logger: Logger, sourceAsset: Asset, destAsset: Asset, destAddress: string, - swapTag?: string, messageMetadata?: CcmDepositMetadata, senderType = SenderType.Address, amount?: string, brokerCommissionBps?: number, - log = true, swapContext?: SwapContext, ) { - const tag = swapTag ?? ''; - - if (log) - console.log( - `${tag} The args are: ${sourceAsset} ${destAsset} ${destAddress} ${ - messageMetadata - ? messageMetadata.message.substring(0, 6) + - '...' + - messageMetadata.message.substring(messageMetadata.message.length - 4) - : '' - }`, - ); + logger.trace( + `The args are: ${sourceAsset} ${destAsset} ${destAddress} ${ + messageMetadata + ? messageMetadata.message.substring(0, 6) + + '...' + + messageMetadata.message.substring(messageMetadata.message.length - 4) + : '' + }`, + ); const swapParams = await requestNewSwap( + logger, sourceAsset, destAsset, destAddress, - tag, messageMetadata, brokerCommissionBps, - log, ); - await doPerformSwap(swapParams, tag, messageMetadata, senderType, amount, log, swapContext); + await doPerformSwap(logger, swapParams, messageMetadata, senderType, amount, swapContext); return swapParams; } // function to create a swap and track it until we detect the corresponding broadcast success export async function performAndTrackSwap( + logger: Logger, sourceAsset: Asset, destAsset: Asset, destAddress: string, amount?: string, - tag?: string, ) { await using chainflipApi = await getChainflipApi(); - const swapParams = await requestNewSwap(sourceAsset, destAsset, destAddress, tag); + const swapParams = await requestNewSwap(logger, sourceAsset, destAsset, destAddress); - await send(sourceAsset, swapParams.depositAddress, amount); - console.log(`${tag} fund sent, waiting for the deposit to be witnessed..`); + await send(logger, sourceAsset, swapParams.depositAddress, amount); + logger.debug(`Funds sent, waiting for the deposit to be witnessed..`); // SwapScheduled, SwapExecuted, SwapEgressScheduled, BatchBroadcastRequested - const broadcastId = await observeSwapEvents(swapParams, chainflipApi, tag); + const broadcastId = await observeSwapEvents(logger, swapParams, chainflipApi); - if (broadcastId) await observeBroadcastSuccess(broadcastId, tag); - else throw new Error('Failed to retrieve broadcastId!'); - console.log(`${tag} broadcast executed successfully, swap is complete!`); + if (broadcastId) { + await observeBroadcastSuccess(logger, broadcastId); + } else { + throwError(logger, new Error(`Failed to retrieve broadcastId!`)); + } + logger.debug(`Broadcast executed successfully, swap is complete!`); } export async function executeVaultSwap( + logger: Logger, sourceAsset: Asset, destAsset: Asset, destAddress: string, @@ -279,15 +279,17 @@ export async function executeVaultSwap( }; if (evmChains.includes(srcChain)) { + logger.trace('Executing EVM vault swap'); // Generate a new wallet for each vault swap to prevent nonce issues when running in parallel // with other swaps via deposit channels. - const wallet = await createEvmWalletAndFund(sourceAsset); + const wallet = await createEvmWalletAndFund(logger, sourceAsset); sourceAddress = wallet.address.toLowerCase(); // To uniquely identify the VaultSwap, we need to use the TX hash. This is only known // after sending the transaction, so we send it first and observe the events afterwards. // There are still multiple blocks of safety margin inbetween before the event is emitted const txHash = await executeEvmVaultSwap( + logger, brokerFeesValue.account, sourceAsset, destAsset, @@ -304,7 +306,9 @@ export async function executeVaultSwap( transactionId = { type: TransactionOrigin.VaultSwapEvm, txHash }; sourceAddress = wallet.address.toLowerCase(); } else if (srcChain === 'Bitcoin') { + logger.trace('Executing BTC vault swap'); const txId = await buildAndSendBtcVaultSwap( + logger, Number(amount ?? defaultAssetAmounts(sourceAsset)), destAsset, destAddress, @@ -318,7 +322,9 @@ export async function executeVaultSwap( // Unused for now sourceAddress = ''; } else { + logger.trace('Executing Solana vault swap'); const { slot, accountAddress } = await executeSolVaultSwap( + logger, sourceAsset, destAsset, destAddress, @@ -341,13 +347,12 @@ export async function executeVaultSwap( } export async function performVaultSwap( + logger: Logger, sourceAsset: Asset, destAsset: Asset, destAddress: string, - swapTag = '', messageMetadata?: CcmDepositMetadata, swapContext?: SwapContext, - log = true, amount?: string, boostFeeBps?: number, fillOrKillParams?: FillOrKillParamsX128, @@ -361,18 +366,16 @@ export async function performVaultSwap( commissionBps: number; }[] = [], ): Promise { - const tag = swapTag ?? ''; - const oldBalance = await getBalance(destAsset, destAddress); - if (log) { - console.log(`${tag} Old balance: ${oldBalance}`); - console.log( - `${tag} Executing (${sourceAsset}) vault swap to(${destAsset}) ${destAddress}. Current balance: ${oldBalance}`, - ); - } + + logger.trace(`Old balance: ${oldBalance}`); + logger.trace( + `Executing (${sourceAsset}) vault swap to(${destAsset}) ${destAddress}. Current balance: ${oldBalance}`, + ); try { const { transactionId, sourceAddress } = await executeVaultSwap( + logger, sourceAsset, destAsset, destAddress, @@ -384,36 +387,40 @@ export async function performVaultSwap( brokerFees, affiliateFees, ); - swapContext?.updateStatus(swapTag, SwapStatus.VaultSwapInitiated); + swapContext?.updateStatus(logger, SwapStatus.VaultSwapInitiated); - await observeSwapRequested(sourceAsset, destAsset, transactionId, SwapRequestType.Regular); + await observeSwapRequested( + logger, + sourceAsset, + destAsset, + transactionId, + SwapRequestType.Regular, + ); - swapContext?.updateStatus(swapTag, SwapStatus.VaultSwapScheduled); + swapContext?.updateStatus(logger, SwapStatus.VaultSwapScheduled); const ccmEventEmitted = messageMetadata ? observeCcmReceived(sourceAsset, destAsset, destAddress, messageMetadata, sourceAddress) : Promise.resolve(); const [newBalance] = await Promise.all([ - observeBalanceIncrease(destAsset, destAddress, oldBalance), + observeBalanceIncrease(logger, destAsset, destAddress, oldBalance), ccmEventEmitted, ]); - if (log) { - console.log(`${tag} Swap success! New balance: ${newBalance}!`); - } + logger.trace(`Swap success! New balance: ${newBalance}!`); + if (sourceAsset === 'Sol') { // Native Vault swaps are fetched proactively. SPL-tokens don't need a fetch. const swapEndpointNativeVaultAddress = getContractAddress( 'Solana', 'SWAP_ENDPOINT_NATIVE_VAULT_ACCOUNT', ); - if (log) - console.log( - `${tag} Waiting for Swap Endpoint Native Vault Swap Fetch ${swapEndpointNativeVaultAddress}`, - ); + logger.trace( + `$Waiting for Swap Endpoint Native Vault Swap Fetch ${swapEndpointNativeVaultAddress}`, + ); await observeFetch(sourceAsset, swapEndpointNativeVaultAddress); } - swapContext?.updateStatus(swapTag, SwapStatus.Success); + swapContext?.updateStatus(logger, SwapStatus.Success); return { sourceAsset, destAsset, @@ -421,11 +428,10 @@ export async function performVaultSwap( transactionId, }; } catch (err) { - console.error('err:', err); - swapContext?.updateStatus(swapTag, SwapStatus.Failure); + swapContext?.updateStatus(logger, SwapStatus.Failure); if (err instanceof Error) { - console.log(err.stack); + logger.trace(err.stack); } - throw new Error(`${tag} ${err}`); + return throwError(logger, new Error(`${err}`)); } } diff --git a/bouncer/shared/range_order.ts b/bouncer/shared/range_order.ts index 3d74236126..7c0fb6c1d7 100644 --- a/bouncer/shared/range_order.ts +++ b/bouncer/shared/range_order.ts @@ -7,8 +7,15 @@ import { createStateChainKeypair, } from '../shared/utils'; import { getChainflipApi, observeEvent } from './utils/substrate'; +import { Logger } from './utils/logger'; -export async function rangeOrder(ccy: Asset, amount: number, lpKey?: string, orderId?: number) { +export async function rangeOrder( + logger: Logger, + ccy: Asset, + amount: number, + lpKey?: string, + orderId?: number, +) { const fineAmount = amountToFineAmount(String(amount), assetDecimals(ccy)); await using chainflip = await getChainflipApi(); @@ -22,8 +29,8 @@ export async function rangeOrder(ccy: Asset, amount: number, lpKey?: string, ord ).toJSON(); const currentSqrtPrice = currentPools!.poolState.rangeOrders.currentSqrtPrice; const liquidity = BigInt(Math.round((currentSqrtPrice / 2 ** 96) * Number(fineAmount))); - console.log('Setting up ' + ccy + ' range order'); - const orderCreatedEvent = observeEvent('liquidityPools:RangeOrderUpdated', { + logger.debug('Setting up ' + ccy + ' range order'); + const orderCreatedEvent = observeEvent(logger, 'liquidityPools:RangeOrderUpdated', { test: (event) => event.data.lp === lp.address && event.data.baseAsset === ccy && diff --git a/bouncer/shared/redeem_flip.ts b/bouncer/shared/redeem_flip.ts index 581217c276..e3b583919a 100644 --- a/bouncer/shared/redeem_flip.ts +++ b/bouncer/shared/redeem_flip.ts @@ -17,6 +17,7 @@ import { createStateChainKeypair, } from './utils'; import { getChainflipApi, observeEvent } from './utils/substrate'; +import { Logger } from './utils/logger'; export type RedeemAmount = 'Max' | { Exact: string }; @@ -31,6 +32,7 @@ function intoFineAmount(amount: RedeemAmount): RedeemAmount { const gatewayAbi = await getGatewayAbi(); export async function redeemFlip( + logger: Logger, flipSeed: string, ethAddress: HexString, flipAmount: RedeemAmount, @@ -57,8 +59,8 @@ export async function redeemFlip( `A redemption is already in progress for this account: ${accountIdHex}, amount: ${pendingRedemption}`, ); - console.log('Requesting redemption'); - const redemptionRequestHandle = observeEvent('funding:RedemptionRequested', { + logger.debug('Requesting redemption'); + const redemptionRequestHandle = observeEvent(logger, 'funding:RedemptionRequested', { test: (event) => event.data.accountId === flipWallet.address, }).event; const flipperinoRedeemAmount = intoFineAmount(flipAmount); @@ -67,9 +69,9 @@ export async function redeemFlip( .signAndSend(flipWallet, { nonce: -1 }, handleSubstrateError(chainflip)); const redemptionRequestEvent = await redemptionRequestHandle; - console.log('Redemption requested: ', redemptionRequestEvent.data.amount); + logger.debug('Redemption requested: ', redemptionRequestEvent.data.amount); - console.log('Waiting for redemption to be registered'); + logger.debug('Waiting for redemption to be registered'); const observeEventAmount = flipperinoRedeemAmount === 'Max' ? '*' : flipperinoRedeemAmount.Exact; await observeEVMEvent( chainFromAsset(Assets.Flip), @@ -80,20 +82,20 @@ export async function redeemFlip( ); const delay = await getRedemptionDelay(networkOptions); - console.log(`Waiting for ${delay}s before we can execute redemption`); + logger.debug(`Waiting for ${delay}s before we can execute redemption`); await sleep(Number(delay) * 1000); - console.log(`Executing redemption`); + logger.debug(`Executing redemption`); const nonce = await getNextEvmNonce('Ethereum'); - const redemptionExecutedHandle = observeEvent('funding:RedemptionSettled', { + const redemptionExecutedHandle = observeEvent(logger, 'funding:RedemptionSettled', { test: (event) => event.data[0] === flipWallet.address, }).event; await executeRedemption(accountIdHex, networkOptions, { nonce }); const redemptionExecutedAmount = (await redemptionExecutedHandle).data[1]; - console.log('Observed RedemptionSettled event: ', redemptionExecutedAmount); + logger.debug('Observed RedemptionSettled event: ', redemptionExecutedAmount); assert.strictEqual( redemptionExecutedAmount, redemptionRequestEvent.data.amount, diff --git a/bouncer/shared/safe_mode.ts b/bouncer/shared/safe_mode.ts index 046113dfa1..a0c18ab463 100644 --- a/bouncer/shared/safe_mode.ts +++ b/bouncer/shared/safe_mode.ts @@ -1,8 +1,9 @@ import { submitGovernanceExtrinsic } from './cf_governance'; +import { globalLogger } from './utils/logger'; import { observeEvent } from './utils/substrate'; async function setSafeMode(mode: string, options?: TranslatedOptions) { - const eventHandle = observeEvent('environment:RuntimeSafeModeUpdated'); + const eventHandle = observeEvent(globalLogger, 'environment:RuntimeSafeModeUpdated'); await submitGovernanceExtrinsic((api) => api.tx.environment.updateSafeMode({ [mode]: options })); await eventHandle.event; @@ -36,7 +37,7 @@ export async function setSafeModeToAmber(options: string[]) { const entry = x.split('_'); translatedOptions[entry[0]][entry[1]] = true; } catch { - console.log('The provided feature flag ' + x + ' is not supported!'); + globalLogger.error(`The provided feature flag ${x} is not supported!`); process.exit(-1); } }); diff --git a/bouncer/shared/send.ts b/bouncer/shared/send.ts index 521f66fc34..2e102797bb 100644 --- a/bouncer/shared/send.ts +++ b/bouncer/shared/send.ts @@ -16,59 +16,65 @@ import { approveErc20 } from './approve_erc20'; import { getCFTesterAbi } from './contract_interfaces'; import { sendSol } from './send_sol'; import { sendSolUsdc } from './send_solusdc'; +import { Logger } from './utils/logger'; const cfTesterAbi = await getCFTesterAbi(); -export async function send(asset: Asset, address: string, amount?: string, log = true) { +export async function send(logger: Logger, asset: Asset, address: string, amount?: string) { switch (asset) { case 'Btc': - await sendBtc(address, amount ?? defaultAssetAmounts(asset)); + await sendBtc(logger, address, amount ?? defaultAssetAmounts(asset)); break; case 'Eth': - await sendEvmNative('Ethereum', address, amount ?? defaultAssetAmounts(asset), log); + await sendEvmNative(logger, 'Ethereum', address, amount ?? defaultAssetAmounts(asset)); break; case 'ArbEth': - await sendEvmNative('Arbitrum', address, amount ?? defaultAssetAmounts(asset), log); + await sendEvmNative(logger, 'Arbitrum', address, amount ?? defaultAssetAmounts(asset)); break; case 'Dot': await sendDot(address, amount ?? defaultAssetAmounts(asset)); break; case 'Sol': - await sendSol(address, amount ?? defaultAssetAmounts(asset)); + await sendSol(logger, address, amount ?? defaultAssetAmounts(asset)); break; case 'Usdc': case 'Usdt': case 'Flip': { const contractAddress = getContractAddress('Ethereum', asset); await sendErc20( + logger, 'Ethereum', address, contractAddress, amount ?? defaultAssetAmounts(asset), - log, ); break; } case 'ArbUsdc': { const contractAddress = getContractAddress('Arbitrum', asset); await sendErc20( + logger, 'Arbitrum', address, contractAddress, amount ?? defaultAssetAmounts(asset), - log, ); break; } case 'SolUsdc': - await sendSolUsdc(address, amount ?? defaultAssetAmounts(asset)); + await sendSolUsdc(logger, address, amount ?? defaultAssetAmounts(asset)); break; default: throw new Error(`Unsupported asset type: ${asset}`); } } -export async function sendViaCfTester(asset: Asset, toAddress: string, amount?: string) { +export async function sendViaCfTester( + logger: Logger, + asset: Asset, + toAddress: string, + amount?: string, +) { const chain = chainFromAsset(asset); const web3 = new Web3(getEvmEndpoint(chain)); @@ -86,7 +92,7 @@ export async function sendViaCfTester(asset: Asset, toAddress: string, amount?: break; case 'Usdc': case 'Flip': { - await approveErc20(asset, cfTesterAddress, amount ?? defaultAssetAmounts(asset)); + await approveErc20(logger, asset, cfTesterAddress, amount ?? defaultAssetAmounts(asset)); txData = cfTesterContract.methods .transferToken( toAddress, @@ -100,5 +106,5 @@ export async function sendViaCfTester(asset: Asset, toAddress: string, amount?: throw new Error(`Unsupported asset type: ${asset}`); } - await signAndSendTxEvm(chain, cfTesterAddress, value, txData); + await signAndSendTxEvm(logger, chain, cfTesterAddress, value, txData); } diff --git a/bouncer/shared/send_btc.ts b/bouncer/shared/send_btc.ts index 5f026cf607..d8910c9299 100644 --- a/bouncer/shared/send_btc.ts +++ b/bouncer/shared/send_btc.ts @@ -1,5 +1,6 @@ import Client from 'bitcoin-core'; import { sleep, btcClientMutex } from './utils'; +import { Logger, throwError } from './utils/logger'; export const BTC_ENDPOINT = process.env.BTC_ENDPOINT || 'http://127.0.0.1:8332'; @@ -54,7 +55,10 @@ export async function sendVaultTransaction( ); } -export async function waitForBtcTransaction(txid: string, confirmations = 1) { +export async function waitForBtcTransaction(logger: Logger, txid: string, confirmations = 1) { + logger.debug( + `Waiting for Btc transaction to be confirmed, txid: ${txid}, required confirmations: ${confirmations}`, + ); for (let i = 0; i < 50; i++) { const transactionDetails = await btcClient.getTransaction(txid); @@ -64,10 +68,14 @@ export async function waitForBtcTransaction(txid: string, confirmations = 1) { return; } } - throw new Error(`Timeout waiting for Btc transaction to be confirmed, txid: ${txid}`); + throwError( + logger, + new Error(`Timeout waiting for Btc transaction to be confirmed, txid: ${txid}`), + ); } export async function sendBtc( + logger: Logger, address: string, amount: number | string, confirmations = 1, @@ -78,7 +86,7 @@ export async function sendBtc( )) as string; if (confirmations > 0) { - await waitForBtcTransaction(txid, confirmations); + await waitForBtcTransaction(logger, txid, confirmations); } return txid; diff --git a/bouncer/shared/send_erc20.ts b/bouncer/shared/send_erc20.ts index d0578949de..0aa62cc491 100644 --- a/bouncer/shared/send_erc20.ts +++ b/bouncer/shared/send_erc20.ts @@ -3,15 +3,16 @@ import { Chain } from '@chainflip/cli'; import { signAndSendTxEvm } from './send_evm'; import { amountToFineAmount, getEvmEndpoint } from './utils'; import { getErc20abi } from './contract_interfaces'; +import { Logger } from './utils/logger'; const erc20abi = await getErc20abi(); export async function sendErc20( + logger: Logger, chain: Chain, destinationAddress: string, contractAddress: string, amount: string, - log = true, ) { const web3 = new Web3(getEvmEndpoint(chain)); @@ -24,7 +25,7 @@ export async function sendErc20( const txData = contract.methods.transfer(destinationAddress, fineAmount).encodeABI(); - if (log) console.log('Transferring ' + amount + ' ' + symbol + ' to ' + destinationAddress); + logger.trace(`Transferring ${amount} ${symbol} to ${destinationAddress}`); - await signAndSendTxEvm(chain, contractAddress, '0', txData, undefined, log); + await signAndSendTxEvm(logger, chain, contractAddress, '0', txData, undefined); } diff --git a/bouncer/shared/send_evm.ts b/bouncer/shared/send_evm.ts index b59cad24da..a6d501defb 100644 --- a/bouncer/shared/send_evm.ts +++ b/bouncer/shared/send_evm.ts @@ -11,6 +11,7 @@ import { assetDecimals, getContractAddress, } from './utils'; +import { Logger } from './utils/logger'; const nextEvmNonce: { [key in 'Ethereum' | 'Arbitrum']: number | undefined } = { Ethereum: undefined, @@ -50,12 +51,12 @@ export async function getNextEvmNonce( } export async function signAndSendTxEvm( + logger: Logger, chain: Chain, to: string, value?: string, data?: string, gas = chain === 'Arbitrum' ? 5000000 : 200000, - log = true, ) { const web3 = new Web3(getEvmEndpoint(chain)); const whaleKey = getWhaleKey(chain); @@ -77,48 +78,52 @@ export async function signAndSendTxEvm( if (i === numberRetries - 1) { throw new Error(`${chain} transaction failure: ${error}`); } - console.log(`${chain} Retrying transaction. Found error: ${error}`); + logger.error(`${chain} Retrying transaction. Found error: ${error}`); } } if (!receipt) { throw new Error('Receipt not found'); } - if (log) { - console.log( - 'Transaction complete, tx_hash: ' + - receipt.transactionHash + - ' blockNumber: ' + - receipt.blockNumber + - ' blockHash: ' + - receipt.blockHash, - ); - } + logger.trace( + 'Transaction complete, tx_hash: ' + + receipt.transactionHash + + ' blockNumber: ' + + receipt.blockNumber + + ' blockHash: ' + + receipt.blockHash, + ); + return receipt; } export async function sendEvmNative( + logger: Logger, chain: Chain, evmAddress: string, ethAmount: string, - log = true, ) { const weiAmount = amountToFineAmount(ethAmount, assetDecimals('Eth')); - await signAndSendTxEvm(chain, evmAddress, weiAmount, undefined, undefined, log); + await signAndSendTxEvm(logger, chain, evmAddress, weiAmount, undefined, undefined); } -export async function spamEvm(chain: Chain, periodMilisec: number, spam?: () => boolean) { +export async function spamEvm( + logger: Logger, + chain: Chain, + periodMilisec: number, + spam?: () => boolean, +) { const continueSpam = spam ?? (() => true); while (continueSpam()) { /* eslint-disable @typescript-eslint/no-floating-promises */ signAndSendTxEvm( + logger, chain, '0xf39Fd6e51aad88F6F4ce6aB8827279cffFb92266', '1', undefined, undefined, - false, ); await sleep(periodMilisec); } diff --git a/bouncer/shared/send_sol.ts b/bouncer/shared/send_sol.ts index 449938e5cb..6a8a28f003 100644 --- a/bouncer/shared/send_sol.ts +++ b/bouncer/shared/send_sol.ts @@ -12,8 +12,9 @@ import { getSolConnection, getSolWhaleKeyPair, } from './utils'; +import { Logger } from './utils/logger'; -export async function signAndSendTxSol(transaction: Transaction, log = true) { +export async function signAndSendTxSol(logger: Logger, transaction: Transaction) { const connection = getSolConnection(); const whaleKeypair = getSolWhaleKeyPair(); const tx = transaction; @@ -25,17 +26,16 @@ export async function signAndSendTxSol(transaction: Transaction, log = true) { const receipt = await connection.getParsedTransaction(txHash); - if (log) { - console.log('Transaction complete, tx_hash: ' + txHash + ' at slot: ' + receipt!.slot); - } + logger.debug(`Transaction complete, tx_hash: ${txHash} at slot: ${receipt!.slot}`); + return receipt; } export async function signAndSendIxsSol( + logger: Logger, instructions: TransactionInstruction[], prioFee = 0, limitCU = 0, - log = true, ) { const transaction = new Transaction(); @@ -60,10 +60,10 @@ export async function signAndSendIxsSol( transaction.add(item); }); - return signAndSendTxSol(transaction, log); + return signAndSendTxSol(logger, transaction); } -export async function sendSol(solAddress: string, solAmount: string, log = true) { +export async function sendSol(logger: Logger, solAddress: string, solAmount: string) { const lamportsAmount = amountToFineAmount(solAmount, assetDecimals('Sol')); const transaction = new Transaction().add( @@ -73,5 +73,5 @@ export async function sendSol(solAddress: string, solAmount: string, log = true) lamports: BigInt(lamportsAmount), }), ); - return signAndSendTxSol(transaction, log); + return signAndSendTxSol(logger, transaction); } diff --git a/bouncer/shared/send_solusdc.ts b/bouncer/shared/send_solusdc.ts index 7b77f8c267..4eaa617a90 100644 --- a/bouncer/shared/send_solusdc.ts +++ b/bouncer/shared/send_solusdc.ts @@ -12,8 +12,9 @@ import { getSolWhaleKeyPair, } from './utils'; import { signAndSendTxSol } from './send_sol'; +import { Logger } from './utils/logger'; -export async function sendSolUsdc(solAddress: string, usdcAmount: string, log = true) { +export async function sendSolUsdc(logger: Logger, solAddress: string, usdcAmount: string) { const usdcMintPubKey = new PublicKey(getContractAddress('Solana', 'SolUsdc')); const whaleKeypair = getSolWhaleKeyPair(); @@ -37,5 +38,5 @@ export async function sendSolUsdc(solAddress: string, usdcAmount: string, log = BigInt(usdcFineAmount), ), ); - return signAndSendTxSol(transaction, log); + return signAndSendTxSol(logger, transaction); } diff --git a/bouncer/shared/set_minimum_deposit.ts b/bouncer/shared/set_minimum_deposit.ts index 54e7df9900..2bc230436f 100644 --- a/bouncer/shared/set_minimum_deposit.ts +++ b/bouncer/shared/set_minimum_deposit.ts @@ -1,9 +1,10 @@ import { submitGovernanceExtrinsic } from './cf_governance'; import { observeEvent } from './utils/substrate'; import { Asset } from './utils'; +import { Logger } from './utils/logger'; -export async function setMinimumDeposit(asset: Asset, amount: bigint) { - const eventHandle = observeEvent('IngressEgress:MinimumDepositSet'); +export async function setMinimumDeposit(logger: Logger, asset: Asset, amount: bigint) { + const eventHandle = observeEvent(logger, 'IngressEgress:MinimumDepositSet'); switch (asset) { case 'Btc': await submitGovernanceExtrinsic((api) => diff --git a/bouncer/shared/setup_account.ts b/bouncer/shared/setup_account.ts index 6e6ad8b9f6..43fb75aea8 100644 --- a/bouncer/shared/setup_account.ts +++ b/bouncer/shared/setup_account.ts @@ -2,16 +2,17 @@ import assert from 'assert'; import { lpMutex, handleSubstrateError, createStateChainKeypair } from './utils'; import { getChainflipApi, observeEvent } from './utils/substrate'; import { fundFlip } from './fund_flip'; +import { Logger } from './utils/logger'; -export async function setupLpAccount(uri: string) { +export async function setupLpAccount(logger: Logger, uri: string) { const lp = createStateChainKeypair(uri); - await fundFlip(lp.address, '1000'); - console.log(`Registering ${lp.address} as an LP...`); + await fundFlip(logger, lp.address, '1000'); + logger.debug(`Registering ${lp.address} as an LP...`); await using chainflip = await getChainflipApi(); - const eventHandle = observeEvent('accountRoles:AccountRoleRegistered', { + const eventHandle = observeEvent(logger, 'accountRoles:AccountRoleRegistered', { test: (event) => event.data.accountId === lp.address, }).event; @@ -22,11 +23,11 @@ export async function setupLpAccount(uri: string) { }); await eventHandle; - console.log(`${lp.address} successfully registered as an LP`); + logger.debug(`${lp.address} successfully registered as an LP`); } /// Sets up a broker account by registering it as a broker if it is not already registered and funding it with 1000 Flip. -export async function setupBrokerAccount(uri: string) { +export async function setupBrokerAccount(logger: Logger, uri: string) { await using chainflip = await getChainflipApi(); const broker = createStateChainKeypair(uri); @@ -36,10 +37,10 @@ export async function setupBrokerAccount(uri: string) { ).replace(/"/g, ''); if (role === 'null' || role === 'Unregistered') { - await fundFlip(broker.address, '1000'); - console.log(`Registering ${broker.address} as a Broker...`); + await fundFlip(logger, broker.address, '1000'); + logger.debug(`Registering ${broker.address} as a Broker...`); - const eventHandle = observeEvent('accountRoles:AccountRoleRegistered', { + const eventHandle = observeEvent(logger, 'accountRoles:AccountRoleRegistered', { test: (event) => event.data.accountId === broker.address, }).event; @@ -50,7 +51,7 @@ export async function setupBrokerAccount(uri: string) { }); await eventHandle; - console.log(`${broker.address} successfully registered as a Broker`); + logger.debug(`${broker.address} successfully registered as a Broker`); } else { assert.strictEqual( role, diff --git a/bouncer/shared/setup_boost_pools.ts b/bouncer/shared/setup_boost_pools.ts index cd1702968f..a4bb4108c2 100644 --- a/bouncer/shared/setup_boost_pools.ts +++ b/bouncer/shared/setup_boost_pools.ts @@ -9,6 +9,7 @@ import { submitGovernanceExtrinsic } from '../shared/cf_governance'; import { getChainflipApi, Event, observeEvent } from './utils/substrate'; import { addBoostFunds } from '../tests/boost'; import { depositLiquidity } from './deposit_liquidity'; +import { Logger, throwError } from './utils/logger'; export type BoostPoolId = { asset: Asset; @@ -21,9 +22,9 @@ const fundBtcBoostPoolsAmount = 2; // Put 2 BTC in each Btc boost pool after cre /// Submits a single governance extrinsic that creates the boost pools for the given assets and tiers. /// All assets must be be from the same chain. -export async function createBoostPools(newPools: BoostPoolId[]): Promise { +export async function createBoostPools(logger: Logger, newPools: BoostPoolId[]): Promise { if (newPools.length === 0) { - throw new Error('No boost pools to create'); + throwError(logger, new Error('No boost pools to create')); } const chain = chainFromAsset(newPools[0].asset); // eslint-disable-next-line @typescript-eslint/no-explicit-any @@ -31,14 +32,15 @@ export async function createBoostPools(newPools: BoostPoolId[]): Promise { for (const pool of newPools) { if (chainFromAsset(pool.asset) !== chain) { - throw new Error(`All assets must be from the same chain`); + throwError(logger, new Error(`All assets must be from the same chain`)); } if (pool.tier <= 0) { - throw new Error(`Tier value: ${pool.tier} must be larger than 0`); + throwError(logger, new Error(`Tier value: ${pool.tier} must be larger than 0`)); } const observeBoostPoolCreated = observeEvent( + logger, `${chain.toLowerCase()}IngressEgress:BoostPoolCreated`, { test: (event) => @@ -46,13 +48,16 @@ export async function createBoostPools(newPools: BoostPoolId[]): Promise { Number(event.data.boostPool.tier) === pool.tier, }, ).event; - const observeGovernanceFailedExecution = observeEvent(`governance:FailedExecution`).event; + const observeGovernanceFailedExecution = observeEvent( + logger, + `governance:FailedExecution`, + ).event; observeBoostPoolEvents.push( Promise.race([observeBoostPoolCreated, observeGovernanceFailedExecution]), ); } - console.log( + logger.debug( `Creating boost pools for chain ${chain} via governance: ${JSON.stringify(newPools)}`, ); await submitGovernanceExtrinsic((api) => @@ -63,27 +68,27 @@ export async function createBoostPools(newPools: BoostPoolId[]): Promise { for (const event of boostPoolEvents) { if (event.name.method !== 'BoostPoolCreated') { const error = decodeModuleError(event.data[0].Module, await getChainflipApi()); - throw new Error(`Failed to create boost pool: ${error}`); + throwError(logger, new Error(`Failed to create boost pool: ${error}`)); } - console.log( + logger.info( `Boost pools created for ${event.data.boostPool.asset} at ${event.data.boostPool.tier} bps`, ); } } /// Creates 5, 10 and 30 bps tier boost pools for all assets on all chains and then funds the Btc boost pools with some BTC. -export async function setupBoostPools(): Promise { - console.log('=== Creating Boost Pools ==='); +export async function setupBoostPools(logger: Logger): Promise { + logger.info('Creating Boost Pools'); const boostPoolCreationPromises: Promise[] = []; for (const chain of Object.values(Chains)) { - console.log(`Creating boost pools for all ${chain} assets`); + logger.debug(`Creating boost pools for all ${chain} assets`); const newPools: BoostPoolId[] = []; for (const asset of chainConstants[chain].assets) { for (const tier of boostPoolTiers) { if (tier <= 0) { - throw new Error(`Invalid tier value: ${tier}`); + throwError(logger, new Error(`Invalid tier value: ${tier}`)); } newPools.push({ asset: getInternalAsset({ asset, chain }), @@ -91,14 +96,15 @@ export async function setupBoostPools(): Promise { }); } } - boostPoolCreationPromises.push(createBoostPools(newPools)); + boostPoolCreationPromises.push(createBoostPools(logger, newPools)); } await Promise.all(boostPoolCreationPromises); // Add some boost funds for Btc to each boost tier - console.log('Funding Boost Pools'); + logger.info('Funding Boost Pools'); const btcIngressFee = 0.0001; // Some small amount to cover the ingress fee await depositLiquidity( + logger, Assets.Btc, fundBtcBoostPoolsAmount * boostPoolTiers.length + btcIngressFee, false, @@ -107,10 +113,10 @@ export async function setupBoostPools(): Promise { const fundBoostPoolsPromises: Promise[] = []; for (const tier of boostPoolTiers) { fundBoostPoolsPromises.push( - addBoostFunds(Assets.Btc, tier, fundBtcBoostPoolsAmount, '//LP_BOOST'), + addBoostFunds(logger, Assets.Btc, tier, fundBtcBoostPoolsAmount, '//LP_BOOST'), ); } await Promise.all(fundBoostPoolsPromises); - console.log('=== Boost Pools Setup completed ==='); + logger.info('Boost Pools Setup completed'); } diff --git a/bouncer/shared/setup_swaps.ts b/bouncer/shared/setup_swaps.ts index c5a10b3239..06cb26f492 100755 --- a/bouncer/shared/setup_swaps.ts +++ b/bouncer/shared/setup_swaps.ts @@ -2,6 +2,7 @@ import { createLpPool } from '../shared/create_lp_pool'; import { depositLiquidity } from './deposit_liquidity'; import { rangeOrder } from '../shared/range_order'; import { Asset } from './utils'; +import { Logger } from './utils/logger'; export const deposits = new Map([ ['Dot', 200000], @@ -29,62 +30,62 @@ const price = new Map([ ['SolUsdc', 1], ]); -export async function setupSwaps(): Promise { - console.log('=== Setting up for swaps ==='); +export async function setupSwaps(logger: Logger): Promise { + logger.info('Setting up for swaps'); await Promise.all([ - createLpPool('Eth', price.get('Eth')!), - createLpPool('Dot', price.get('Dot')!), - createLpPool('Btc', price.get('Btc')!), - createLpPool('Flip', price.get('Flip')!), - createLpPool('Usdt', price.get('Usdt')!), - createLpPool('ArbEth', price.get('ArbEth')!), - createLpPool('ArbUsdc', price.get('ArbUsdc')!), - createLpPool('Sol', price.get('Sol')!), - createLpPool('SolUsdc', price.get('SolUsdc')!), + createLpPool(logger, 'Eth', price.get('Eth')!), + createLpPool(logger, 'Dot', price.get('Dot')!), + createLpPool(logger, 'Btc', price.get('Btc')!), + createLpPool(logger, 'Flip', price.get('Flip')!), + createLpPool(logger, 'Usdt', price.get('Usdt')!), + createLpPool(logger, 'ArbEth', price.get('ArbEth')!), + createLpPool(logger, 'ArbUsdc', price.get('ArbUsdc')!), + createLpPool(logger, 'Sol', price.get('Sol')!), + createLpPool(logger, 'SolUsdc', price.get('SolUsdc')!), ]); const lp1Deposits = Promise.all([ - depositLiquidity('Usdc', deposits.get('Usdc')!, false, '//LP_1'), - depositLiquidity('Eth', deposits.get('Eth')!, false, '//LP_1'), - depositLiquidity('Dot', deposits.get('Dot')!, false, '//LP_1'), - depositLiquidity('Btc', deposits.get('Btc')!, false, '//LP_1'), - depositLiquidity('Flip', deposits.get('Flip')!, false, '//LP_1'), - depositLiquidity('Usdt', deposits.get('Usdt')!, false, '//LP_1'), - depositLiquidity('ArbEth', deposits.get('ArbEth')!, false, '//LP_1'), - depositLiquidity('ArbUsdc', deposits.get('ArbUsdc')!, false, '//LP_1'), - depositLiquidity('Sol', deposits.get('Sol')!, false, '//LP_1'), - depositLiquidity('SolUsdc', deposits.get('SolUsdc')!, false, '//LP_1'), + depositLiquidity(logger, 'Usdc', deposits.get('Usdc')!, false, '//LP_1'), + depositLiquidity(logger, 'Eth', deposits.get('Eth')!, false, '//LP_1'), + depositLiquidity(logger, 'Dot', deposits.get('Dot')!, false, '//LP_1'), + depositLiquidity(logger, 'Btc', deposits.get('Btc')!, false, '//LP_1'), + depositLiquidity(logger, 'Flip', deposits.get('Flip')!, false, '//LP_1'), + depositLiquidity(logger, 'Usdt', deposits.get('Usdt')!, false, '//LP_1'), + depositLiquidity(logger, 'ArbEth', deposits.get('ArbEth')!, false, '//LP_1'), + depositLiquidity(logger, 'ArbUsdc', deposits.get('ArbUsdc')!, false, '//LP_1'), + depositLiquidity(logger, 'Sol', deposits.get('Sol')!, false, '//LP_1'), + depositLiquidity(logger, 'SolUsdc', deposits.get('SolUsdc')!, false, '//LP_1'), ]); const lpApiDeposits = Promise.all([ - depositLiquidity('Usdc', 1000, false, '//LP_API'), - depositLiquidity('Eth', 100, false, '//LP_API'), - depositLiquidity('Dot', 2000, false, '//LP_API'), - depositLiquidity('Btc', 10, false, '//LP_API'), - depositLiquidity('Flip', 10000, false, '//LP_API'), - depositLiquidity('Usdt', 1000, false, '//LP_API'), - depositLiquidity('ArbEth', 10, false, '//LP_API'), - depositLiquidity('ArbUsdc', 1000, false, '//LP_API'), - depositLiquidity('Sol', 500, false, '//LP_API'), - depositLiquidity('SolUsdc', 1000, false, '//LP_API'), + depositLiquidity(logger, 'Usdc', 1000, false, '//LP_API'), + depositLiquidity(logger, 'Eth', 100, false, '//LP_API'), + depositLiquidity(logger, 'Dot', 2000, false, '//LP_API'), + depositLiquidity(logger, 'Btc', 10, false, '//LP_API'), + depositLiquidity(logger, 'Flip', 10000, false, '//LP_API'), + depositLiquidity(logger, 'Usdt', 1000, false, '//LP_API'), + depositLiquidity(logger, 'ArbEth', 10, false, '//LP_API'), + depositLiquidity(logger, 'ArbUsdc', 1000, false, '//LP_API'), + depositLiquidity(logger, 'Sol', 500, false, '//LP_API'), + depositLiquidity(logger, 'SolUsdc', 1000, false, '//LP_API'), ]); await Promise.all([lp1Deposits, lpApiDeposits]); await Promise.all([ - rangeOrder('Eth', deposits.get('Eth')! * 0.9999), - rangeOrder('Dot', deposits.get('Dot')! * 0.9999), - rangeOrder('Btc', deposits.get('Btc')! * 0.9999), - rangeOrder('Flip', deposits.get('Flip')! * 0.9999), - rangeOrder('Usdt', deposits.get('Usdt')! * 0.9999), - rangeOrder('ArbEth', deposits.get('ArbEth')! * 0.9999), - rangeOrder('ArbUsdc', deposits.get('ArbUsdc')! * 0.9999), - rangeOrder('Sol', deposits.get('Sol')! * 0.9999), - rangeOrder('SolUsdc', deposits.get('SolUsdc')! * 0.9999), + rangeOrder(logger, 'Eth', deposits.get('Eth')! * 0.9999), + rangeOrder(logger, 'Dot', deposits.get('Dot')! * 0.9999), + rangeOrder(logger, 'Btc', deposits.get('Btc')! * 0.9999), + rangeOrder(logger, 'Flip', deposits.get('Flip')! * 0.9999), + rangeOrder(logger, 'Usdt', deposits.get('Usdt')! * 0.9999), + rangeOrder(logger, 'ArbEth', deposits.get('ArbEth')! * 0.9999), + rangeOrder(logger, 'ArbUsdc', deposits.get('ArbUsdc')! * 0.9999), + rangeOrder(logger, 'Sol', deposits.get('Sol')! * 0.9999), + rangeOrder(logger, 'SolUsdc', deposits.get('SolUsdc')! * 0.9999), ]); - console.log('Range orders placed'); + logger.debug('Range orders placed'); - console.log('=== Swaps Setup completed ==='); + logger.info('Swaps Setup completed'); } diff --git a/bouncer/shared/simple_runtime_upgrade.ts b/bouncer/shared/simple_runtime_upgrade.ts index 74e9a76408..8badaa4a72 100755 --- a/bouncer/shared/simple_runtime_upgrade.ts +++ b/bouncer/shared/simple_runtime_upgrade.ts @@ -1,28 +1,31 @@ import { submitRuntimeUpgrade } from './submit_runtime_upgrade'; import { bumpSpecVersionAgainstNetwork, getNetworkRuntimeVersion } from './utils/spec_version'; import { compileBinaries } from './utils/compile_binaries'; +import { Logger } from './utils/logger'; // Do a runtime upgrade using the code in the projectRoot directory. -export async function simpleRuntimeUpgrade(projectRoot: string, tryRuntime = false): Promise { +export async function simpleRuntimeUpgrade( + logger: Logger, + projectRoot: string, + tryRuntime = false, +): Promise { const nextSpecVersion = await bumpSpecVersionAgainstNetwork( + logger, `${projectRoot}/state-chain/runtime/src/lib.rs`, ); await compileBinaries('runtime', projectRoot); - await submitRuntimeUpgrade(projectRoot, tryRuntime); + await submitRuntimeUpgrade(logger, projectRoot, tryRuntime); - const newSpecVersion = (await getNetworkRuntimeVersion()).specVersion; - console.log('New spec_version: ' + newSpecVersion); + const newSpecVersion = (await getNetworkRuntimeVersion(logger)).specVersion; + logger.debug('New spec_version: ' + newSpecVersion); if (newSpecVersion !== nextSpecVersion) { - console.error( - 'After submitting the runtime upgrade, the new spec_version is not what we expected. Expected: ' + - nextSpecVersion + - ' Got: ' + - newSpecVersion, + logger.error( + `After submitting the runtime upgrade, the new spec_version is not what we expected. Expected: ${nextSpecVersion}, Got: ${newSpecVersion}`, ); } - console.log('Runtime upgrade complete.'); + logger.info('Runtime upgrade complete.'); } diff --git a/bouncer/shared/sol_vault_swap.ts b/bouncer/shared/sol_vault_swap.ts index bdedf68e7a..f9d57bd628 100644 --- a/bouncer/shared/sol_vault_swap.ts +++ b/bouncer/shared/sol_vault_swap.ts @@ -31,6 +31,7 @@ import { getSolanaSwapEndpointIdl } from './contract_interfaces'; import { getChainflipApi } from './utils/substrate'; import { getBalance } from './get_balance'; import { TestContext } from './utils/test_context'; +import { Logger, throwError } from './utils/logger'; const createdEventAccounts: [PublicKey, boolean][] = []; @@ -63,6 +64,7 @@ export type ChannelRefundParameters = { }; export async function executeSolVaultSwap( + logger: Logger, srcAsset: Asset, destAsset: Asset, destAddress: string, @@ -111,6 +113,7 @@ export async function executeSolVaultSwap( from_token_account: undefined, }; + logger.trace('Requesting vault swap parameter encoding'); const vaultSwapDetails = (await chainflip.rpc( `cf_request_swap_parameter_encoding`, brokerFees.account, @@ -159,6 +162,7 @@ export async function executeSolVaultSwap( transaction.add(instruction); + logger.trace('Sending Solana vault swap transaction'); const txHash = await sendAndConfirmTransaction( connection, transaction, @@ -168,7 +172,7 @@ export async function executeSolVaultSwap( const transactionData = await connection.getTransaction(txHash, { commitment: 'confirmed' }); if (transactionData === null) { - throw new Error('Solana TransactionData is empty'); + throwError(logger, new Error('Solana TransactionData is empty')); } return { txHash, slot: transactionData!.slot, accountAddress: newEventAccountKeypair.publicKey }; } @@ -178,8 +182,7 @@ export async function checkSolEventAccountsClosure( testContext: TestContext, eventAccounts: [PublicKey, boolean][] = createdEventAccounts, ) { - const logger = testContext.logger; - logger.info('=== Checking Solana Vault Swap Account Closure ==='); + testContext.info('Checking Solana Vault Swap Account Closure'); // eslint-disable-next-line @typescript-eslint/no-explicit-any const SwapEndpointIdl: any = await getSolanaSwapEndpointIdl(); diff --git a/bouncer/shared/submit_runtime_upgrade.ts b/bouncer/shared/submit_runtime_upgrade.ts index 7c5f53f087..de1ae6a7bd 100755 --- a/bouncer/shared/submit_runtime_upgrade.ts +++ b/bouncer/shared/submit_runtime_upgrade.ts @@ -4,6 +4,7 @@ import { submitGovernanceExtrinsic } from './cf_governance'; import { decodeModuleError } from '../shared/utils'; import { tryRuntimeUpgrade } from './try_runtime_upgrade'; import { getChainflipApi, observeEvent } from './utils/substrate'; +import { Logger } from './utils/logger'; async function readRuntimeWasmFromFile(filePath: string): Promise { return compactAddLength(new Uint8Array(await fs.readFile(filePath))); @@ -11,6 +12,7 @@ async function readRuntimeWasmFromFile(filePath: string): Promise { // By default we don't want to restrict that any of the nodes need to be upgraded. export async function submitRuntimeUpgradeWithRestrictions( + logger: Logger, wasmPath: string, semverRestriction?: Record, percentNodesUpgraded = 0, @@ -24,7 +26,7 @@ export async function submitRuntimeUpgradeWithRestrictions( const networkUrl = process.env.CF_NODE_ENDPOINT ?? 'ws://localhost:9944'; if (tryRuntime) { - console.log('Running try-runtime before submitting the runtime upgrade.'); + logger.info('Running try-runtime before submitting the runtime upgrade.'); await tryRuntimeUpgrade('last-n', networkUrl, wasmPath); } @@ -35,16 +37,16 @@ export async function submitRuntimeUpgradeWithRestrictions( versionPercentRestriction = undefined; } - console.log('Submitting runtime upgrade.'); + logger.info('Submitting runtime upgrade.'); await submitGovernanceExtrinsic((api) => api.tx.governance.chainflipRuntimeUpgrade(versionPercentRestriction, runtimeWasm), ); - console.log('Submitted runtime upgrade. Waiting for the runtime upgrade to complete.'); + logger.info('Submitted runtime upgrade. Waiting for the runtime upgrade to complete.'); const event = await Promise.race([ - observeEvent('system:CodeUpdated').event, - observeEvent('governance:FailedExecution').event, + observeEvent(logger, 'system:CodeUpdated').event, + observeEvent(logger, 'governance:FailedExecution').event, ]); if (event.name.method === 'FailedExecution') { @@ -52,16 +54,21 @@ export async function submitRuntimeUpgradeWithRestrictions( throw Error(`Runtime upgrade failed: ${error}`); } - console.log('Runtime upgrade completed.'); + logger.info('Runtime upgrade completed.'); } -export async function submitRuntimeUpgradeWasmPath(wasmPath: string) { - await submitRuntimeUpgradeWithRestrictions(wasmPath); +export async function submitRuntimeUpgradeWasmPath(logger: Logger, wasmPath: string) { + await submitRuntimeUpgradeWithRestrictions(logger, wasmPath); } // Restrictions not provided. -export async function submitRuntimeUpgrade(projectRoot: string, tryRuntime = false) { +export async function submitRuntimeUpgrade( + logger: Logger, + projectRoot: string, + tryRuntime = false, +) { await submitRuntimeUpgradeWithRestrictions( + logger, `${projectRoot}/target/release/wbuild/state-chain-runtime/state_chain_runtime.compact.compressed.wasm`, undefined, 0, diff --git a/bouncer/shared/swapping.ts b/bouncer/shared/swapping.ts index e5d029201f..b57669b2a3 100644 --- a/bouncer/shared/swapping.ts +++ b/bouncer/shared/swapping.ts @@ -14,6 +14,7 @@ import { BtcAddressType } from '../shared/new_btc_address'; import { CcmDepositMetadata } from '../shared/new_swap'; import { SwapContext, SwapStatus } from './utils/swap_context'; import { estimateCcmCfTesterGas } from './send_evm'; +import { Logger } from './utils/logger'; let swapCount = 1; @@ -204,12 +205,12 @@ export async function newVaultSwapCcmMetadata( } export async function prepareSwap( + parentLogger: Logger, sourceAsset: Asset, destAsset: Asset, addressType?: BtcAddressType, messageMetadata?: CcmDepositMetadata, tagSuffix?: string, - log = true, swapContext?: SwapContext, ) { // Seed needs to be unique per swap: @@ -220,6 +221,7 @@ export async function prepareSwap( let tag = `[${(swapCount++).toString().concat(':').padEnd(4, ' ')} ${sourceAsset}->${destAsset}`; tag += messageMetadata ? ' CCM' : ''; tag += tagSuffix ? ` ${tagSuffix}]` : ']'; + const logger = parentLogger.child({ tag }); // For swaps with a message force the address to be the CF Tester address. if ( @@ -229,18 +231,19 @@ export async function prepareSwap( chainFromAsset(destAsset) !== 'Solana' ) { destAddress = getContractAddress(chainFromAsset(destAsset), 'CFTESTER'); - if (log) console.log(`${tag} Using CF Tester address: ${destAddress}`); + logger.trace(`Using CF Tester address: ${destAddress}`); } else { destAddress = await newAddress(destAsset, seed, addressType); - if (log) console.log(`${tag} Created new ${destAsset} address: ${destAddress}`); + logger.trace(`Created new ${destAsset} address: ${destAddress}`); } - swapContext?.updateStatus(tag, SwapStatus.Initiated); + swapContext?.updateStatus(logger, SwapStatus.Initiated); return { destAddress, tag }; } export async function testSwap( + logger: Logger, sourceAsset: Asset, destAsset: Asset, addressType?: BtcAddressType, @@ -248,57 +251,54 @@ export async function testSwap( swapContext?: SwapContext, tagSuffix?: string, amount?: string, - log = true, ) { const { destAddress, tag } = await prepareSwap( + logger, sourceAsset, destAsset, addressType, messageMetadata, tagSuffix, - log, swapContext, ); return performSwap( + logger.child({ tag }), sourceAsset, destAsset, destAddress, - tag, messageMetadata, undefined, amount, undefined, - log, swapContext, ); } export async function testVaultSwap( + logger: Logger, sourceAsset: Asset, destAsset: Asset, addressType?: BtcAddressType, messageMetadata?: CcmDepositMetadata, swapContext?: SwapContext, tagSuffix?: string, - log = true, ) { const { destAddress, tag } = await prepareSwap( + logger, sourceAsset, destAsset, addressType, messageMetadata, (tagSuffix ?? '') + 'Vault', - log, swapContext, ); return performVaultSwap( + logger.child({ tag }), sourceAsset, destAsset, destAddress, - tag, messageMetadata, swapContext, - log, ); } diff --git a/bouncer/shared/upgrade_network.ts b/bouncer/shared/upgrade_network.ts index 14a7a8944e..f0c50758ae 100755 --- a/bouncer/shared/upgrade_network.ts +++ b/bouncer/shared/upgrade_network.ts @@ -10,6 +10,7 @@ import { compileBinaries } from './utils/compile_binaries'; import { submitRuntimeUpgradeWithRestrictions } from './submit_runtime_upgrade'; import { execWithLog } from './utils/exec_with_log'; import { submitGovernanceExtrinsic } from './cf_governance'; +import { globalLogger as logger } from './utils/logger'; async function readPackageTomlVersion(projectRoot: string): Promise { const data = await fs.readFile(path.join(projectRoot, '/state-chain/runtime/Cargo.toml'), 'utf8'); @@ -39,30 +40,30 @@ function createGitWorkspaceAt(nextVersionWorkspacePath: string, toGitRef: string // Navigate to the new workspace and checkout the specific commit execSync(`cd ${nextVersionWorkspacePath} && git checkout ${toGitRef}`); - console.log('Commit checked out successfully in new workspace.'); + logger.info('Commit checked out successfully in new workspace.'); } catch (error) { console.error(`Error: ${error}`); } } function killOldNodes() { - console.log('Killing the old node.'); + logger.info('Killing the old node.'); try { const execOutput = execSync( `kill $(ps -o pid -o comm | grep chainflip-node | awk '{print $1}')`, ); - console.log('Kill node exec output:', execOutput.toString()); + logger.info('Kill node exec output:', execOutput.toString()); } catch (e) { - console.log('Error killing node: ' + e); + logger.info('Error killing node: ' + e); throw e; } - console.log('Killed old node'); + logger.info('Killed old node'); } async function startBrokerAndLpApi(localnetInitPath: string, binaryPath: string, keysDir: string) { - console.log('Starting new broker and lp-api.'); + logger.info('Starting new broker and lp-api.'); execWithLog(`${localnetInitPath}/scripts/start-broker-api.sh ${binaryPath}`, 'start-broker-api', { KEYS_DIR: keysDir, @@ -80,7 +81,7 @@ async function startBrokerAndLpApi(localnetInitPath: string, binaryPath: string, ]) { try { const pid = execSync(`lsof -t -i:${port}`); - console.log(`New ${process} PID: ${pid.toString()}`); + logger.info(`New ${process} PID: ${pid.toString()}`); } catch (e) { console.error(`Error starting ${process}: ${e}`); throw e; @@ -89,7 +90,7 @@ async function startBrokerAndLpApi(localnetInitPath: string, binaryPath: string, } async function startDepositMonitor(localnetInitPath: string) { - console.log('Starting up deposit-monitor.'); + logger.info('Starting up deposit-monitor.'); let done = false; execWithLog( @@ -123,7 +124,7 @@ async function compatibleUpgrade( runtimePath: string, numberOfNodes: 1 | 3, ) { - await submitRuntimeUpgradeWithRestrictions(runtimePath, undefined, undefined, true); + await submitRuntimeUpgradeWithRestrictions(logger, runtimePath, undefined, undefined, true); killOldNodes(); @@ -170,13 +171,13 @@ async function incompatibleUpgradeNoBuild( ) { // We need to kill the engine process before starting the new engine (engine-runner) // Since the new engine contains the old one. - console.log('Killing the old engines'); + logger.info('Killing the old engines'); await killEngines(); await startEngines(localnetInitPath, binaryPath, numberOfNodes); - await submitRuntimeUpgradeWithRestrictions(runtimePath, undefined, undefined, true); + await submitRuntimeUpgradeWithRestrictions(logger, runtimePath, undefined, undefined, true); - console.log( + logger.info( 'Check that the old engine has now shut down, and that the new engine is now running.', ); @@ -195,7 +196,7 @@ async function incompatibleUpgradeNoBuild( }), ); - console.log('Submitted extrinsic to set suspension for MissedAuthorship slot to 0'); + logger.info('Submitted extrinsic to set suspension for MissedAuthorship slot to 0'); // Ensure extrinsic gets in. await sleep(12000); @@ -204,9 +205,9 @@ async function incompatibleUpgradeNoBuild( // let them shutdown await sleep(4000); - console.log('Old broker and LP-API have crashed since we killed the node.'); + logger.info('Old broker and LP-API have crashed since we killed the node.'); - console.log('Starting the new node'); + logger.info('Starting the new node'); const KEYS_DIR = `${localnetInitPath}/keys`; @@ -231,7 +232,7 @@ async function incompatibleUpgradeNoBuild( ); const output = execSync("ps -o pid -o comm | grep chainflip-node | awk '{print $1}'"); - console.log('New node PID: ' + output.toString()); + logger.info('New node PID: ' + output.toString()); // Restart the engines execWithLog( @@ -250,10 +251,10 @@ async function incompatibleUpgradeNoBuild( await sleep(4000); await startBrokerAndLpApi(localnetInitPath, binaryPath, KEYS_DIR); - console.log('Started new broker and lp-api.'); + logger.info('Started new broker and lp-api.'); await startDepositMonitor(localnetInitPath); - console.log('Started new deposit monitor.'); + logger.info('Started new deposit monitor.'); } async function incompatibleUpgrade( @@ -262,7 +263,10 @@ async function incompatibleUpgrade( nextVersionWorkspacePath: string, numberOfNodes: 1 | 3, ) { - await bumpSpecVersionAgainstNetwork(`${nextVersionWorkspacePath}/state-chain/runtime/src/lib.rs`); + await bumpSpecVersionAgainstNetwork( + logger, + `${nextVersionWorkspacePath}/state-chain/runtime/src/lib.rs`, + ); await compileBinaries('all', nextVersionWorkspacePath); @@ -282,21 +286,21 @@ export async function upgradeNetworkGit( bumpByIfEqual: SemVerLevel = 'patch', numberOfNodes: 1 | 3 = 1, ) { - console.log('Upgrading network to git ref: ' + toGitRef); + logger.info('Upgrading network to git ref: ' + toGitRef); const currentVersionWorkspacePath = path.dirname(process.cwd()); const fromTomlVersion = await readPackageTomlVersion(currentVersionWorkspacePath); - console.log("Version we're upgrading from: " + fromTomlVersion); + logger.info("Version we're upgrading from: " + fromTomlVersion); // tmp/ is ignored in the bouncer .gitignore file. const nextVersionWorkspacePath = path.join(process.cwd(), 'tmp/upgrade-network'); - console.log('Creating a new git workspace at: ' + nextVersionWorkspacePath); + logger.info('Creating a new git workspace at: ' + nextVersionWorkspacePath); createGitWorkspaceAt(nextVersionWorkspacePath, toGitRef); const toTomlVersion = await readPackageTomlVersion(`${nextVersionWorkspacePath}`); - console.log("Version of commit we're upgrading to: " + toTomlVersion); + logger.info("Version of commit we're upgrading to: " + toTomlVersion); if (compareSemVer(fromTomlVersion, toTomlVersion) === 'greater') { throw new Error( @@ -306,34 +310,34 @@ export async function upgradeNetworkGit( // Now we need to bump the TOML versions if required, to ensure the `CurrentReleaseVersion` in the environment pallet is correct. if (fromTomlVersion === toTomlVersion) { - console.log('Versions are equal, bumping by: ' + bumpByIfEqual); + logger.info('Versions are equal, bumping by: ' + bumpByIfEqual); await bumpReleaseVersion(bumpByIfEqual, nextVersionWorkspacePath); } else { - console.log('Versions are not equal, no need to bump.'); + logger.info('Versions are not equal, no need to bump.'); } const newToTomlVersion = await readPackageTomlVersion(path.join(nextVersionWorkspacePath)); - console.log("Version we're upgrading to: " + newToTomlVersion); + logger.info("Version we're upgrading to: " + newToTomlVersion); const isCompatible = isCompatibleWith(fromTomlVersion, newToTomlVersion); - console.log('Is compatible: ' + isCompatible); + logger.info('Is compatible: ' + isCompatible); const localnetInitPath = `${currentVersionWorkspacePath}/localnet/init`; if (isCompatible) { - console.log('The versions are compatible.'); - await simpleRuntimeUpgrade(nextVersionWorkspacePath, true); + logger.info('The versions are compatible.'); + await simpleRuntimeUpgrade(logger, nextVersionWorkspacePath, true); // TODO: Add restart nodes support, as in the prebuilt case. - console.log('Upgrade complete.'); + logger.info('Upgrade complete.'); } else if (!isCompatible) { - console.log('The versions are incompatible.'); + logger.info('The versions are incompatible.'); await incompatibleUpgrade(localnetInitPath, nextVersionWorkspacePath, numberOfNodes); } - console.log('Cleaning up...'); + logger.info('Cleaning up...'); execSync(`cd ${nextVersionWorkspacePath} && git worktree remove . --force`); - console.log('Done.'); + logger.info('Done.'); } export async function upgradeNetworkPrebuilt( @@ -350,18 +354,18 @@ export async function upgradeNetworkPrebuilt( ) { const versionRegex = /\d+\.\d+\.\d+/; - console.log("Raw version we're upgrading from: " + oldVersion); + logger.info("Raw version we're upgrading from: " + oldVersion); let cleanOldVersion = oldVersion; if (versionRegex.test(cleanOldVersion)) { cleanOldVersion = oldVersion.match(versionRegex)?.[0] ?? ''; } - console.log("Version we're upgrading from: " + cleanOldVersion); + logger.info("Version we're upgrading from: " + cleanOldVersion); const nodeBinaryVersion = execSync(`${binariesPath}/chainflip-node --version`).toString(); const nodeVersion = nodeBinaryVersion.match(versionRegex)?.[0] ?? ''; - console.log("Node version we're upgrading to: " + nodeVersion); + logger.info("Node version we're upgrading to: " + nodeVersion); // We use nodeVersion as a proxy for the cfe version since they are updated together. // And getting the cfe version involves ensuring the dylib is available. @@ -376,12 +380,12 @@ export async function upgradeNetworkPrebuilt( 'The versions are the same. No need to upgrade. Please provide a different version.', ); } else if (isCompatibleWith(cleanOldVersion, nodeVersion)) { - console.log('The versions are compatible.'); + logger.info('The versions are compatible.'); await compatibleUpgrade(localnetInitPath, binariesPath, runtimePath, numberOfNodes); } else { - console.log('The versions are incompatible.'); + logger.info('The versions are incompatible.'); await incompatibleUpgradeNoBuild(localnetInitPath, binariesPath, runtimePath, numberOfNodes); } - console.log('Upgrade complete.'); + logger.info('Upgrade complete.'); } diff --git a/bouncer/shared/utils.ts b/bouncer/shared/utils.ts index dba2ca0608..27519dd9ff 100644 --- a/bouncer/shared/utils.ts +++ b/bouncer/shared/utils.ts @@ -34,6 +34,7 @@ import { getChainflipApi, observeBadEvent, observeEvent } from './utils/substrat import { execWithLog } from './utils/exec_with_log'; import { send } from './send'; import { TestContext } from './utils/test_context'; +import { Logger, throwError } from './utils/logger'; const cfTesterAbi = await getCFTesterAbi(); const cfTesterIdl = await getCfTesterIdl(); @@ -242,50 +243,6 @@ export function chainGasAsset(chain: Chain): Asset { } } -/// Simplified color logging with reset, so only a single line will be colored. -/// Example: console.log(ConsoleLogColors.Red, 'message'); -export enum ConsoleLogColors { - WhiteBold = '\x1b[1m%s\x1b[0m', - DarkGrey = '\x1b[2m%s\x1b[0m', - Underline = '\x1b[4m%s\x1b[0m', - Grey = '\x1b[30m%s\x1b[0m', - Green = '\x1b[32m%s\x1b[0m', - Red = '\x1b[31m%s\x1b[0m', - Yellow = '\x1b[33m%s\x1b[0m', - Blue = '\x1b[34m%s\x1b[0m', - Purple = '\x1b[35m%s\x1b[0m', - LightBlue = '\x1b[36m%s\x1b[0m', - RedSolid = '\x1b[41m%s\x1b[0m', -} - -export const ConsoleColors = { - Reset: '\x1b[0m', - Bright: '\x1b[1m', - Dim: '\x1b[2m', - Underscore: '\x1b[4m', - Blink: '\x1b[5m', - Reverse: '\x1b[7m', - Hidden: '\x1b[8m', - - FgBlack: '\x1b[30m', - FgRed: '\x1b[31m', - FgGreen: '\x1b[32m', - FgYellow: '\x1b[33m', - FgBlue: '\x1b[34m', - FgMagenta: '\x1b[35m', - FgCyan: '\x1b[36m', - FgWhite: '\x1b[37m', - - BgBlack: '\x1b[40m', - BgRed: '\x1b[41m', - BgGreen: '\x1b[42m', - BgYellow: '\x1b[43m', - BgBlue: '\x1b[44m', - BgMagenta: '\x1b[45m', - BgCyan: '\x1b[46m', - BgWhite: '\x1b[47m', -}; - export function amountToFineAmountBigInt(amount: number | string, asset: Asset): bigint { const stringAmount = typeof amount === 'number' ? amount.toString() : amount; return BigInt(amountToFineAmount(stringAmount, assetDecimals(asset))); @@ -322,10 +279,7 @@ export async function runWithTimeoutAndExit( const executionTime = (Date.now() - start) / 1000; if (executionTime > seconds * 0.9) { - console.warn( - ConsoleLogColors.Yellow, - `Warning: Execution time was close to the timeout: ${executionTime}/${seconds}s`, - ); + console.warn(`Warning: Execution time was close to the timeout: ${executionTime}/${seconds}s`); } else { console.log(`Execution time: ${executionTime}/${seconds}s`); } @@ -389,9 +343,9 @@ export type EgressId = [Chain, number]; type BroadcastChainAndId = [Chain, number]; // Observe multiple events related to the same swap that could be emitted in the same block export async function observeSwapEvents( + logger: Logger, { sourceAsset, destAsset, depositAddress, channelId }: SwapParams, api: ApiPromise, - tag?: string, finalized = false, ): Promise { let broadcastEventFound = false; @@ -452,21 +406,21 @@ export async function observeSwapEvents( case swapExecutedEvent: if (data.swapId === swapId) { expectedEvent = swapEgressScheduled; - console.log(`${tag} swap executed, with id: ${swapId}`); + logger.trace(`Swap executed, with id: ${swapId}`); } break; case swapEgressScheduled: if (data.swapRequestId === swapRequestId) { expectedEvent = batchBroadcastRequested; egressId = data.egressId as EgressId; - console.log(`${tag} swap egress scheduled with id: (${egressId[0]}, ${egressId[1]})`); + logger.trace(`Swap egress scheduled with id: (${egressId[0]}, ${egressId[1]})`); } break; case batchBroadcastRequested: for (const eventEgressId of data.egressIds) { if (egressId[0] === eventEgressId[0] && egressId[1] === eventEgressId[1]) { broadcastId = [egressId[0], Number(data.broadcastId)] as BroadcastChainAndId; - console.log(`${tag} broadcast requested, with id: (${broadcastId})`); + logger.trace(`Broadcast requested, with id: (${broadcastId})`); broadcastEventFound = true; unsubscribe(); break; @@ -551,13 +505,14 @@ function checkTransactionInMatches(actual: any, expected: TransactionOriginId): } export async function observeSwapRequested( + logger: Logger, sourceAsset: Asset, destAsset: Asset, id: TransactionOriginId, swapRequestType: SwapRequestType, ) { // need to await this to prevent the chainflip api from being disposed prematurely - return observeEvent('swapping:SwapRequested', { + return observeEvent(logger, 'swapping:SwapRequested', { test: (event) => { const data = event.data; @@ -575,16 +530,15 @@ export async function observeSwapRequested( }).event; } -export async function observeBroadcastSuccess(broadcastId: BroadcastChainAndId, testTag?: string) { +export async function observeBroadcastSuccess(logger: Logger, broadcastId: BroadcastChainAndId) { const broadcaster = broadcastId[0].toLowerCase() + 'Broadcaster'; const broadcastIdNumber = broadcastId[1]; - const observeBroadcastFailure = observeBadEvent(`${broadcaster}:BroadcastAborted`, { + const observeBroadcastFailure = observeBadEvent(logger, `${broadcaster}:BroadcastAborted`, { test: (event) => broadcastIdNumber === Number(event.data.broadcastId), - label: testTag ? `observe BroadcastSuccess test tag: ${testTag}` : 'observe BroadcastSuccess', }); - await observeEvent(`${broadcaster}:BroadcastSuccess`, { + await observeEvent(logger, `${broadcaster}:BroadcastSuccess`, { test: (event) => broadcastIdNumber === Number(event.data.broadcastId), }).event; @@ -684,10 +638,12 @@ export function getWhaleKey(chain: Chain): string { } export async function observeBalanceIncrease( + logger: Logger, dstCcy: Asset, address: string, oldBalance: string, ): Promise { + logger.debug(`Observing balance increase of ${dstCcy} at ${address}`); for (let i = 0; i < 2400; i++) { const newBalance = Number(await getBalance(dstCcy, address)); if (newBalance > Number(oldBalance)) { @@ -697,7 +653,7 @@ export async function observeBalanceIncrease( await sleep(3000); } - return Promise.reject(new Error('Failed to observe balance increase')); + return throwError(logger, new Error('Failed to observe balance increase')); } export async function observeFetch(asset: Asset, address: string): Promise { @@ -1169,7 +1125,7 @@ export async function startEngines( // Check that all Solana Nonces are available export async function checkAvailabilityAllSolanaNonces(testContext: TestContext) { - testContext.info('=== Checking Solana Nonce Availability ==='); + testContext.info('Checking Solana Nonce Availability'); // Check that all Solana nonces are available await using chainflip = await getChainflipApi(); @@ -1216,7 +1172,7 @@ export function getTimeStamp(): string { return `${hours}:${minutes}:${seconds}`; } -export async function createEvmWalletAndFund(asset: Asset): Promise { +export async function createEvmWalletAndFund(logger: Logger, asset: Asset): Promise { const chain = chainFromAsset(asset); const mnemonic = Wallet.createRandom().mnemonic?.phrase ?? ''; @@ -1224,7 +1180,7 @@ export async function createEvmWalletAndFund(asset: Asset): Promise void, -) { +function logMethod(this: pino.Logger, args: Parameters, method: pino.LogFn) { const newArgs = args; if (args.length === 2 && !args[0].includes('%s')) { newArgs[0] = `${args[0]} %s`; @@ -29,10 +27,12 @@ function logMethod( method.apply(this, newArgs); } -export const logger: Logger = pino( +export const globalLogger: Logger = pino( { hooks: { logMethod }, level: 'trace', + // We don't want to log the hostname or pid + base: undefined, timestamp: pino.stdTimeFunctions.isoTime, // Log the level as a string ("info") instead of a number (30) formatters: { @@ -40,21 +40,36 @@ export const logger: Logger = pino( }, }, pino.multistream([ - { stream: prettyConsoleTransport, level: 'info' }, + { stream: prettyConsoleTransport, level: process.env.BOUNCER_LOG_LEVEL ?? 'info' }, { stream: logFileDestination, level: 'trace' }, ]), ); process.on('uncaughtException', (err) => { - logger.error(err); + globalLogger.error(err); }); process.on('unhandledRejection', (reason, promise) => { - logger.error({ reason, promise }); + globalLogger.error({ reason, promise }); }); -// Creates a child logger and appends the module name to any existing module names +// Creates a child logger and appends the module name to any existing module names on the logger export function loggerChild(parentLogger: Logger, name: string): Logger { const existingModule = parentLogger.bindings().module as string | undefined; const newModule = existingModule !== undefined ? `${existingModule}::${name}` : name; return parentLogger.child({ module: newModule }); } + +// Takes all of the contextual information attached to the logger and appends it to the error message +export function loggerError(parentLogger: Logger, error: Error): Error { + const bindings = parentLogger.bindings(); + const newError = error; + for (const [key, value] of Object.entries(bindings)) { + newError.message += `\n ${key}: ${value}`; + } + return newError; +} + +// Takes all of the contextual information attached to the logger and appends it to the error message before throwing it +export function throwError(parentLogger: Logger, error: Error): never { + throw loggerError(parentLogger, error); +} diff --git a/bouncer/shared/utils/spec_version.ts b/bouncer/shared/utils/spec_version.ts index 2386d1889e..18d43a1854 100644 --- a/bouncer/shared/utils/spec_version.ts +++ b/bouncer/shared/utils/spec_version.ts @@ -1,5 +1,6 @@ import fs from 'fs'; import { jsonRpc } from '../json_rpc'; +import { Logger } from './logger'; type RuntimeVersion = { specName: string; @@ -12,11 +13,20 @@ type RuntimeVersion = { stateVersion: number; }; -export async function getNetworkRuntimeVersion(endpoint?: string): Promise { - return (await jsonRpc('state_getRuntimeVersion', [], endpoint)) as unknown as RuntimeVersion; +export async function getNetworkRuntimeVersion( + logger: Logger, + endpoint?: string, +): Promise { + return (await jsonRpc( + logger, + 'state_getRuntimeVersion', + [], + endpoint, + )) as unknown as RuntimeVersion; } export function specVersion( + logger: Logger, filePath: string, readOrWrite: 'read' | 'write', // Will only write this version if the current version is less than this. @@ -49,7 +59,7 @@ export function specVersion( if (writeSpecVersion) { if (currentSpecVersion >= writeSpecVersion) { - console.log( + logger.info( "Current spec version is greater than the one you're trying to write. Returning currentSpecVersion.", ); return currentSpecVersion; @@ -79,7 +89,7 @@ export function specVersion( const updatedContent = lines.join('\n'); fs.writeFileSync(filePath, updatedContent); - console.log(`Successfully updated spec_version to ${incrementedVersion}.`); + logger.info(`Successfully updated spec_version to ${incrementedVersion}.`); return incrementedVersion; // eslint-disable-next-line @typescript-eslint/no-explicit-any } catch (error: any) { @@ -90,13 +100,14 @@ export function specVersion( // Bump the spec version in the runtime file, using the spec version of the network. export async function bumpSpecVersionAgainstNetwork( + logger: Logger, runtimeLibPath: string, endpoint?: string, ): Promise { - const networkSpecVersion = (await getNetworkRuntimeVersion(endpoint)).specVersion; - console.log('Current spec_version: ' + networkSpecVersion); + const networkSpecVersion = (await getNetworkRuntimeVersion(logger, endpoint)).specVersion; + logger.debug('Current spec_version: ' + networkSpecVersion); const nextSpecVersion = networkSpecVersion + 1; - console.log('Bumping the spec version to: ' + nextSpecVersion); - specVersion(runtimeLibPath, 'write', nextSpecVersion); + logger.info('Bumping the spec version to: ' + nextSpecVersion); + specVersion(logger, runtimeLibPath, 'write', nextSpecVersion); return nextSpecVersion; } diff --git a/bouncer/shared/utils/substrate.ts b/bouncer/shared/utils/substrate.ts index 093afbb574..2bd698c2c7 100644 --- a/bouncer/shared/utils/substrate.ts +++ b/bouncer/shared/utils/substrate.ts @@ -2,6 +2,7 @@ import 'disposablestack/auto'; import { ApiPromise, WsProvider } from '@polkadot/api'; import { Observable, Subject } from 'rxjs'; import { deferredPromise, sleep } from '../utils'; +import { Logger } from './logger'; // @ts-expect-error polyfilling Symbol.asyncDispose ??= Symbol('asyncDispose'); @@ -369,13 +370,19 @@ type AbortableObserver = { }; /* eslint-disable @typescript-eslint/no-explicit-any */ -export function observeEvents(eventName: EventName): Observer; -export function observeEvents(eventName: EventName, opts: Options): Observer; +export function observeEvents(logger: Logger, eventName: EventName): Observer; export function observeEvents( + logger: Logger, + eventName: EventName, + opts: Options, +): Observer; +export function observeEvents( + logger: Logger, eventName: EventName, opts: AbortableOptions, ): AbortableObserver; export function observeEvents( + logger: Logger, eventName: EventName, { chain = 'chainflip', @@ -386,6 +393,7 @@ export function observeEvents( }: Options | AbortableOptions = {}, ) { const [expectedSection, expectedMethod] = eventName.split(':'); + logger.trace(`Observing event ${eventName}`); const controller = abortable ? new AbortController() : undefined; @@ -402,6 +410,7 @@ export function observeEvents( test(event) ) { foundEvents.push(event); + logger.trace(`Found event ${eventName} in block ${event.block}`); } } } @@ -421,6 +430,7 @@ export function observeEvents( test(event) ) { foundEvents.push(event); + logger.trace(`Found event ${eventName} in block ${event.block}`); } } if (foundEvents.length > 0) { @@ -445,17 +455,20 @@ type SingleEventObserver = { event: Promise>; }; -export function observeEvent(eventName: EventName): SingleEventObserver; +export function observeEvent(logger: Logger, eventName: EventName): SingleEventObserver; export function observeEvent( + logger: Logger, eventName: EventName, opts: Options, ): SingleEventObserver; export function observeEvent( + logger: Logger, eventName: EventName, opts: AbortableOptions, ): SingleEventAbortableObserver; export function observeEvent( + logger: Logger, eventName: EventName, { chain = 'chainflip', @@ -466,7 +479,7 @@ export function observeEvent( }: Options | AbortableOptions = {}, ): SingleEventObserver | SingleEventAbortableObserver { if (abortable) { - const observer = observeEvents(eventName, { + const observer = observeEvents(logger, eventName, { chain, test, finalized, @@ -480,7 +493,7 @@ export function observeEvent( } as SingleEventAbortableObserver; } - const observer = observeEvents(eventName, { + const observer = observeEvents(logger, eventName, { chain, test, finalized, @@ -496,10 +509,11 @@ export function observeEvent( /* eslint-disable @typescript-eslint/no-explicit-any */ export function observeBadEvent( + logger: Logger, eventName: EventName, - { test, label }: { test?: EventTest; label?: string }, + { test }: { test?: EventTest }, ): { stop: () => Promise } { - const observer = observeEvent(eventName, { test, abortable: true }); + const observer = observeEvent(logger, eventName, { test, abortable: true }); return { stop: async () => { @@ -508,7 +522,7 @@ export function observeBadEvent( await observer.event.then((event) => { if (event) { throw new Error( - `Unexpected event emitted ${event.name.section}:${event.name.method} in block ${event.block} [${label}]`, + `Unexpected event emitted ${event.name.section}:${event.name.method} in block ${event.block}`, ); } }); diff --git a/bouncer/shared/utils/swap_context.ts b/bouncer/shared/utils/swap_context.ts index 2476e1b76e..4ef9989fe0 100644 --- a/bouncer/shared/utils/swap_context.ts +++ b/bouncer/shared/utils/swap_context.ts @@ -1,5 +1,5 @@ import assert from 'assert'; -import { logger as globalLogger, Logger } from './logger'; +import { globalLogger, Logger, loggerError, throwError } from './logger'; export enum SwapStatus { Initiated, @@ -18,43 +18,66 @@ export class SwapContext { this.allSwaps = new Map(); } - updateStatus(tag: string, status: SwapStatus) { + updateStatus(logger: Logger, status: SwapStatus) { + // Get the tag from the logger + const tag = logger.bindings().tag; + if (!tag) { + throwError( + logger, + new Error(`No tag found on logger when trying to update swap status to ${status}`), + ); + } const currentStatus = this.allSwaps.get(tag); - // Sanity checks: + // State transition checks: switch (status) { case SwapStatus.Initiated: { assert( currentStatus === undefined, - `Unexpected status transition for ${tag}. Transitioning from ${currentStatus} to ${status}`, + loggerError( + logger, + new Error(`Unexpected status transition from ${currentStatus} to ${status}`), + ), ); break; } case SwapStatus.Funded: { assert( currentStatus === SwapStatus.Initiated, - `Unexpected status transition for ${tag}. Transitioning from ${currentStatus} to ${status}`, + loggerError( + logger, + new Error(`Unexpected status transition from ${currentStatus} to ${status}`), + ), ); break; } case SwapStatus.VaultSwapInitiated: { assert( currentStatus === SwapStatus.Initiated, - `Unexpected status transition for ${tag}. Transitioning from ${currentStatus} to ${status}`, + loggerError( + logger, + new Error(`Unexpected status transition from ${currentStatus} to ${status}`), + ), ); break; } case SwapStatus.VaultSwapScheduled: { assert( currentStatus === SwapStatus.VaultSwapInitiated, - `Unexpected status transition for ${tag}. Transitioning from ${currentStatus} to ${status}`, + loggerError( + logger, + new Error(`Unexpected status transition from ${currentStatus} to ${status}`), + ), ); break; } case SwapStatus.SwapScheduled: { assert( currentStatus === SwapStatus.Funded, - `Unexpected status transition for ${tag}. Transitioning from ${currentStatus} to ${status}`, + loggerError( + logger, + new Error(`Unexpected status transition from ${currentStatus} to ${status}`), + ), ); break; } @@ -62,7 +85,10 @@ export class SwapContext { assert( currentStatus === SwapStatus.SwapScheduled || currentStatus === SwapStatus.VaultSwapScheduled, - `Unexpected status transition for ${tag}. Transitioning from ${currentStatus} to ${status}`, + loggerError( + logger, + new Error(`Unexpected status transition from ${currentStatus} to ${status}`), + ), ); break; } diff --git a/bouncer/shared/utils/test_context.ts b/bouncer/shared/utils/test_context.ts index 265a734cab..79dc0c848e 100644 --- a/bouncer/shared/utils/test_context.ts +++ b/bouncer/shared/utils/test_context.ts @@ -1,4 +1,4 @@ -import { logger as globalLogger, Logger } from './logger'; +import { globalLogger, Logger } from './logger'; import { SwapContext } from './swap_context'; export class TestContext { diff --git a/bouncer/shared/utils/vitest.ts b/bouncer/shared/utils/vitest.ts index 9f3af4c7e3..bb15340c83 100644 --- a/bouncer/shared/utils/vitest.ts +++ b/bouncer/shared/utils/vitest.ts @@ -14,12 +14,14 @@ function createTestFunction(name: string, testFunction: (context: TestContext) = return async (context: { testContext: TestContext }) => { // Attach the test name to the logger context.testContext.logger = context.testContext.logger.child({ test: name }); + context.testContext.logger.info(`🧪 Starting test ${name}`); // Run the test with the test context await testFunction(context.testContext).catch((error) => { // We must catch the error here to be able to log it context.testContext.error(error); throw error; }); + context.testContext.logger.info(`✅ Finished test ${name}`); }; } export function concurrentTest( diff --git a/bouncer/test_commands/delta_based_ingress.ts b/bouncer/test_commands/delta_based_ingress.ts index a9dae8f151..410204a496 100755 --- a/bouncer/test_commands/delta_based_ingress.ts +++ b/bouncer/test_commands/delta_based_ingress.ts @@ -14,7 +14,7 @@ import yargs from 'yargs'; import { hideBin } from 'yargs/helpers'; import { testDeltaBasedIngress } from '../tests/delta_based_ingress'; import { TestContext } from '../shared/utils/test_context'; -import { logger } from '../shared/utils/logger'; +import { globalLogger } from '../shared/utils/logger'; import { runWithTimeoutAndExit } from '../shared/utils'; // Test Solana's delta based ingress @@ -24,7 +24,7 @@ async function main(): Promise { 'prebuilt', 'specify paths to the prebuilt binaries and runtime you wish to upgrade to', (args) => { - logger.info('prebuilt selected'); + globalLogger.info('prebuilt selected'); return args .option('bins', { describe: 'paths to the binaries and runtime you wish to upgrade to', diff --git a/bouncer/tests/DCA_test.ts b/bouncer/tests/DCA_test.ts index d75c32f521..cb379c3f21 100644 --- a/bouncer/tests/DCA_test.ts +++ b/bouncer/tests/DCA_test.ts @@ -49,13 +49,12 @@ async function testDCASwap( if (!swapViaVault) { const swapRequest = await requestNewSwap( + logger.child({ tag: `DCA_test_${inputAsset}` }), inputAsset, destAsset, destAddress, - 'DCA_Test', undefined, // messageMetadata 0, // brokerCommissionBps - false, // log 0, // boostFeeBps fillOrKillParams, dcaParams, @@ -63,6 +62,7 @@ async function testDCASwap( const depositChannelId = swapRequest.channelId; swapRequestedHandle = observeSwapRequested( + logger, inputAsset, destAsset, { type: TransactionOrigin.DepositChannel, channelId: depositChannelId }, @@ -70,10 +70,11 @@ async function testDCASwap( ); // Deposit the asset - await send(inputAsset, swapRequest.depositAddress, amount.toString()); + await send(logger, inputAsset, swapRequest.depositAddress, amount.toString()); logger.debug(`Sent ${amount} ${inputAsset} to ${swapRequest.depositAddress}`); } else { const { transactionId } = await executeVaultSwap( + logger, inputAsset, destAsset, destAddress, @@ -88,6 +89,7 @@ async function testDCASwap( // Look after Swap Requested of data.origin.Vault.tx_hash swapRequestedHandle = observeSwapRequested( + logger, inputAsset, destAsset, transactionId, @@ -101,12 +103,12 @@ async function testDCASwap( ); // Wait for the swap to complete - await observeEvent(`swapping:SwapRequestCompleted`, { + await observeEvent(logger, `swapping:SwapRequestCompleted`, { test: (event) => Number(event.data.swapRequestId.replaceAll(',', '')) === swapRequestId, }).event; // Find the `SwapExecuted` events for this swap. - const observeSwapExecutedEvents = await observeEvents(`swapping:SwapExecuted`, { + const observeSwapExecutedEvents = await observeEvents(logger, `swapping:SwapExecuted`, { test: (event) => Number(event.data.swapRequestId.replaceAll(',', '')) === swapRequestId, historicalCheckBlocks: numberOfChunks * CHUNK_INTERVAL + 10, }).events; @@ -130,7 +132,7 @@ async function testDCASwap( logger.debug(`Chunk interval of ${CHUNK_INTERVAL} verified for all ${numberOfChunks} chunks`); - await observeBalanceIncrease(destAsset, destAddress, destBalanceBefore); + await observeBalanceIncrease(logger, destAsset, destAddress, destBalanceBefore); } export async function testDCASwaps(testContext: TestContext) { diff --git a/bouncer/tests/all_swaps.ts b/bouncer/tests/all_swaps.ts index 99739be25d..b6e302a788 100644 --- a/bouncer/tests/all_swaps.ts +++ b/bouncer/tests/all_swaps.ts @@ -14,11 +14,10 @@ import { vaultSwapSupportedChains, } from '../shared/utils'; import { openPrivateBtcChannel } from '../shared/btc_vault_swap'; -import { SwapContext } from '../shared/utils/swap_context'; import { TestContext } from '../shared/utils/test_context'; export async function initiateSwap( - swapContext: SwapContext, + testContext: TestContext, sourceAsset: Asset, destAsset: Asset, functionCall: typeof testSwap | typeof testVaultSwap, @@ -35,21 +34,29 @@ export async function initiateSwap( if (destAsset === 'Btc') { const btcAddressTypesArray = Object.values(btcAddressTypes); return functionCall( + testContext.logger, sourceAsset, destAsset, btcAddressTypesArray[Math.floor(Math.random() * btcAddressTypesArray.length)], ccmSwapMetadata, - swapContext, + testContext.swapContext, ); } - return functionCall(sourceAsset, destAsset, undefined, ccmSwapMetadata, swapContext); + return functionCall( + testContext.logger, + sourceAsset, + destAsset, + undefined, + ccmSwapMetadata, + testContext.swapContext, + ); } export async function testAllSwaps(textContext: TestContext) { const allSwaps: Promise[] = []; // Open a private BTC channel to be used for btc vault swaps - await openPrivateBtcChannel('//BROKER_1'); + await openPrivateBtcChannel(textContext.logger, '//BROKER_1'); function appendSwap( sourceAsset: Asset, @@ -57,9 +64,7 @@ export async function testAllSwaps(textContext: TestContext) { functionCall: typeof testSwap | typeof testVaultSwap, ccmSwap: boolean = false, ) { - allSwaps.push( - initiateSwap(textContext.swapContext, sourceAsset, destAsset, functionCall, ccmSwap), - ); + allSwaps.push(initiateSwap(textContext, sourceAsset, destAsset, functionCall, ccmSwap)); } Object.values(Assets).forEach((sourceAsset) => { diff --git a/bouncer/tests/boost.ts b/bouncer/tests/boost.ts index 93efc588a9..593995fac2 100644 --- a/bouncer/tests/boost.ts +++ b/bouncer/tests/boost.ts @@ -20,10 +20,12 @@ import { createBoostPools } from '../shared/setup_boost_pools'; import { jsonRpc } from '../shared/json_rpc'; import { observeEvent, Event, getChainflipApi } from '../shared/utils/substrate'; import { TestContext } from '../shared/utils/test_context'; +import { Logger, throwError } from '../shared/utils/logger'; /// Stops boosting for the given boost pool tier and returns the StoppedBoosting event. /* eslint-disable @typescript-eslint/no-explicit-any */ export async function stopBoosting( + logger: Logger, asset: Asset, boostTier: number, lpUri = '//LP_BOOST', @@ -36,6 +38,7 @@ export async function stopBoosting( assert(boostTier > 0, 'Boost tier must be greater than 0'); const observeStoppedBoosting = observeEvent( + logger, `${chainFromAsset(asset).toLowerCase()}IngressEgress:StoppedBoosting`, { test: (event) => @@ -53,15 +56,16 @@ export async function stopBoosting( errorOnFail, ); if (!extrinsicResult?.dispatchError) { - console.log('waiting for stop boosting event'); + logger.debug('waiting for stop boosting event'); return observeStoppedBoosting; } - console.log('Already stopped boosting'); + logger.debug('Already stopped boosting'); return undefined; } /// Adds existing funds to the boost pool of the given tier and returns the BoostFundsAdded event. export async function addBoostFunds( + logger: Logger, asset: Asset, boostTier: number, amount: number, @@ -74,6 +78,7 @@ export async function addBoostFunds( assert(boostTier > 0, 'Boost tier must be greater than 0'); const observeBoostFundsAdded = observeEvent( + logger, `${chainFromAsset(asset).toLowerCase()}IngressEgress:BoostFundsAdded`, { test: (event) => @@ -84,7 +89,7 @@ export async function addBoostFunds( ); // Add funds to the boost pool - console.log(`Adding boost funds of ${amount} ${asset} at ${boostTier}bps`); + logger.debug(`Adding boost funds of ${amount} ${asset} at ${boostTier}bps`); await extrinsicSubmitter.submit( chainflip.tx[ingressEgressPalletForChain(chainFromAsset(asset))].addBoostFunds( shortChainFromAsset(asset).toUpperCase(), @@ -104,11 +109,11 @@ async function testBoostingForAsset( amount: number, testContext: TestContext, ) { - const logger = testContext.logger; - logger.debug(`Testing boosting for ${asset} at ${boostFee}bps`); + const logger = testContext.logger.child({ boostAsset: asset, boostFee }); + logger.debug(`Testing boosting`); // Start with a clean slate by stopping boosting before the test - const preTestStopBoostingEvent = await stopBoosting(asset, boostFee, lpUri, false); + const preTestStopBoostingEvent = await stopBoosting(logger, asset, boostFee, lpUri, false); assert.strictEqual( preTestStopBoostingEvent?.data?.pendingBoosts?.length ?? 0, 0, @@ -116,7 +121,7 @@ async function testBoostingForAsset( ); const boostPoolDetails = ( - (await jsonRpc('cf_boost_pool_details', [Assets.Btc.toUpperCase()])) as any + (await jsonRpc(logger, 'cf_boost_pool_details', [Assets.Btc.toUpperCase()])) as any )[0]; assert.strictEqual(boostPoolDetails.fee_tier, boostFee, 'Unexpected lowest fee tier'); assert.strictEqual( @@ -126,54 +131,55 @@ async function testBoostingForAsset( ); // Add boost funds - await depositLiquidity(asset, amount * 1.01, false, lpUri); - await addBoostFunds(asset, boostFee, amount, lpUri); + await depositLiquidity(logger, asset, amount * 1.01, false, lpUri); + await addBoostFunds(logger, asset, boostFee, amount, lpUri); // Do a swap const swapAsset = asset === Assets.Usdc ? Assets.Flip : Assets.Usdc; const destAddress = await newAddress(swapAsset, 'LP_BOOST'); - console.log(`Swap destination address: ${destAddress}`); + logger.debug(`Swap destination address: ${destAddress}`); const swapRequest = await requestNewSwap( + logger, asset, swapAsset, destAddress, undefined, - undefined, 0, - false, boostFee, ); const observeDepositFinalised = observeEvent( + logger, `${chainFromAsset(asset).toLowerCase()}IngressEgress:DepositFinalised`, { test: (event) => event.data.channelId === swapRequest.channelId.toString(), }, ).event; const observeSwapBoosted = observeEvent( + logger, `${chainFromAsset(asset).toLowerCase()}IngressEgress:DepositBoosted`, { test: (event) => event.data.channelId === swapRequest.channelId.toString(), }, ).event; - await send(asset, swapRequest.depositAddress, amount.toString()); + await send(logger, asset, swapRequest.depositAddress, amount.toString()); logger.debug(`Sent ${amount} ${asset} to ${swapRequest.depositAddress}`); // Check that the swap was boosted const depositEvent = await Promise.race([observeSwapBoosted, observeDepositFinalised]); if (depositEvent.name.method === 'DepositFinalised') { - throw new Error('Deposit was finalised without seeing the DepositBoosted event'); + throwError(logger, new Error('Deposit was finalised without seeing the DepositBoosted event')); } else if (depositEvent.name.method !== 'DepositBoosted') { - throw new Error(`Unexpected event ${depositEvent.name.method}`); + throwError(logger, new Error(`Unexpected event ${depositEvent.name.method}`)); } const depositFinalisedEvent = await observeDepositFinalised; - logger.debug('DepositFinalised event:', JSON.stringify(depositFinalisedEvent)); + logger.trace('DepositFinalised event:', JSON.stringify(depositFinalisedEvent)); // Stop boosting - const stoppedBoostingEvent = await stopBoosting(asset, boostFee, lpUri)!; - logger.debug('StoppedBoosting event:', JSON.stringify(stoppedBoostingEvent)); + const stoppedBoostingEvent = await stopBoosting(logger, asset, boostFee, lpUri)!; + logger.trace('StoppedBoosting event:', JSON.stringify(stoppedBoostingEvent)); assert.strictEqual( stoppedBoostingEvent?.data.pendingBoosts.length, 0, @@ -205,7 +211,9 @@ export async function testBoostingSwap(testContext: TestContext) { // Create the boost pool if it doesn't exist if (!boostPool?.feeBps) { - await createBoostPools([{ asset: Assets.Btc, tier: boostPoolTier }]); + await createBoostPools(testContext.logger, [{ asset: Assets.Btc, tier: boostPoolTier }]); + } else { + testContext.trace(`Boost pool already exists for tier ${boostPoolTier}`); } // Pre-witnessing is only enabled for btc at the moment. Add the other assets here when it's enabled for them. diff --git a/bouncer/tests/broker_fee_collection.ts b/bouncer/tests/broker_fee_collection.ts index 00d1d37424..1e88b2034c 100644 --- a/bouncer/tests/broker_fee_collection.ts +++ b/bouncer/tests/broker_fee_collection.ts @@ -75,7 +75,7 @@ async function testBrokerFees(logger: Logger, inputAsset: Asset, seed?: string): // we need to manually create the swap channel and observe the relative event // because we want to use a separate broker to not interfere with other tests - const addressPromise = observeEvent('swapping:SwapDepositAddressReady', { + const addressPromise = observeEvent(logger, 'swapping:SwapDepositAddressReady', { test: (event) => { // Find deposit address for the right swap by looking at destination address: const destAddressEvent = event.data.destinationAddress[shortChainFromAsset(destAsset)]; @@ -105,20 +105,21 @@ async function testBrokerFees(logger: Logger, inputAsset: Asset, seed?: string): const channelId = Number(res.channelId); const swapRequestedHandle = observeSwapRequested( + logger, inputAsset, destAsset, { type: TransactionOrigin.DepositChannel, channelId }, SwapRequestType.Regular, ); - await send(inputAsset, depositAddress, rawDepositForSwapAmount, true /* log */); + await send(logger, inputAsset, depositAddress, rawDepositForSwapAmount); const swapRequestedEvent = (await swapRequestedHandle).data; // Get values from the swap event const requestId = swapRequestedEvent.swapRequestId; - const swapExecutedEvent = await observeEvent('swapping:SwapExecuted', { + const swapExecutedEvent = await observeEvent(logger, 'swapping:SwapExecuted', { test: (event) => event.data.swapRequestId === requestId, }).event; @@ -153,7 +154,7 @@ async function testBrokerFees(logger: Logger, inputAsset: Asset, seed?: string): logger.debug( `Withdrawing broker fees to ${withdrawalAddress}, balance before: ${balanceBeforeWithdrawal}`, ); - const observeWithdrawalRequested = observeEvent('swapping:WithdrawalRequested', { + const observeWithdrawalRequested = observeEvent(logger, 'swapping:WithdrawalRequested', { test: (event) => event.data.destinationAddress[chain]?.toLowerCase() === withdrawalAddress.toLowerCase(), }); @@ -167,7 +168,7 @@ async function testBrokerFees(logger: Logger, inputAsset: Asset, seed?: string): logger.debug(`Withdrawal requested, egressId: ${withdrawalRequestedEvent.data.egressId}`); - await observeBalanceIncrease(feeAsset, withdrawalAddress, balanceBeforeWithdrawal); + await observeBalanceIncrease(logger, feeAsset, withdrawalAddress, balanceBeforeWithdrawal); // Check that the balance after withdrawal is correct after deducting withdrawal fee const balanceAfterWithdrawal = await getBalance(feeAsset, withdrawalAddress); diff --git a/bouncer/tests/broker_level_screening.ts b/bouncer/tests/broker_level_screening.ts index e3b045c8d0..583dba8337 100644 --- a/bouncer/tests/broker_level_screening.ts +++ b/bouncer/tests/broker_level_screening.ts @@ -15,6 +15,7 @@ import { requestNewSwap } from '../shared/perform_swap'; import { FillOrKillParamsX128 } from '../shared/new_swap'; import { getBtcBalance } from '../shared/get_btc_balance'; import { TestContext } from '../shared/utils/test_context'; +import { Logger } from '../shared/utils/logger'; const keyring = new Keyring({ type: 'sr25519' }); const broker = keyring.createFromUri('//BROKER_1'); @@ -148,6 +149,7 @@ async function ensureHealth() { * @returns - The the channel id of the deposit channel. */ async function brokerLevelScreeningTestScenario( + logger: Logger, amount: string, doBoost: boolean, refundAddress: string, @@ -160,17 +162,16 @@ async function brokerLevelScreeningTestScenario( minPriceX128: '0', }; const swapParams = await requestNewSwap( + logger.child({ tag: 'brokerLevelScreeningTest' }), 'Btc', 'Usdc', destinationAddressForUsdc, - 'brokerLevelScreeningTest', undefined, 0, - true, doBoost ? 100 : 0, refundParameters, ); - const txId = await sendBtc(swapParams.depositAddress, amount, 0); + const txId = await sendBtc(logger, swapParams.depositAddress, amount, 0); await reportFunction(txId); return swapParams.channelId.toString(); } @@ -197,11 +198,11 @@ export async function testBrokerLevelScreening( logger.debug('Testing broker level screening with no boost...'); let btcRefundAddress = await newAssetAddress('Btc'); - await brokerLevelScreeningTestScenario('0.2', false, btcRefundAddress, async (txId) => + await brokerLevelScreeningTestScenario(logger, '0.2', false, btcRefundAddress, async (txId) => setTxRiskScore(txId, 9.0), ); - await observeEvent('bitcoinIngressEgress:TransactionRejectedByBroker').event; + await observeEvent(logger, 'bitcoinIngressEgress:TransactionRejectedByBroker').event; if (!(await observeBtcAddressBalanceChange(btcRefundAddress))) { throw new Error(`Didn't receive funds refund to address ${btcRefundAddress} within timeout!`); } @@ -214,10 +215,10 @@ export async function testBrokerLevelScreening( logger.debug('Testing broker level screening with boost and a early tx report...'); btcRefundAddress = await newAssetAddress('Btc'); - await brokerLevelScreeningTestScenario('0.2', true, btcRefundAddress, async (txId) => + await brokerLevelScreeningTestScenario(logger, '0.2', true, btcRefundAddress, async (txId) => setTxRiskScore(txId, 9.0), ); - await observeEvent('bitcoinIngressEgress:TransactionRejectedByBroker').event; + await observeEvent(logger, 'bitcoinIngressEgress:TransactionRejectedByBroker').event; if (!(await observeBtcAddressBalanceChange(btcRefundAddress))) { throw new Error(`Didn't receive funds refund to address ${btcRefundAddress} within timeout!`); @@ -230,6 +231,7 @@ export async function testBrokerLevelScreening( btcRefundAddress = await newAssetAddress('Btc'); const channelId = await brokerLevelScreeningTestScenario( + logger, '0.2', true, btcRefundAddress, @@ -242,7 +244,7 @@ export async function testBrokerLevelScreening( }, ); - await observeEvent('bitcoinIngressEgress:DepositFinalised', { + await observeEvent(logger, 'bitcoinIngressEgress:DepositFinalised', { test: (event) => event.data.channelId === channelId, }).event; diff --git a/bouncer/tests/btc_utxo_consolidation.ts b/bouncer/tests/btc_utxo_consolidation.ts index 70cae9fd32..81c836bc0e 100755 --- a/bouncer/tests/btc_utxo_consolidation.ts +++ b/bouncer/tests/btc_utxo_consolidation.ts @@ -48,8 +48,8 @@ export async function testBtcUtxoConsolidation(testContext: TestContext) { const consolidationThreshold = initialUtxos.count + 2; // Add 2 utxo which should later trigger consolidation as per the parameters above: - await depositLiquidity('Btc', 2); - await depositLiquidity('Btc', 3); + await depositLiquidity(logger, 'Btc', 2); + await depositLiquidity(logger, 'Btc', 3); const amountBeforeConsolidation = (await queryUtxos()).amount; logger.debug(`Total amount in BTC vault is: ${amountBeforeConsolidation}`); @@ -58,7 +58,10 @@ export async function testBtcUtxoConsolidation(testContext: TestContext) { `Setting consolidation threshold to: ${consolidationThreshold} and size to: ${consolidationSize}`, ); - const consolidationEventPromise = observeEvent('bitcoinIngressEgress:UtxoConsolidation').event; + const consolidationEventPromise = observeEvent( + logger, + 'bitcoinIngressEgress:UtxoConsolidation', + ).event; // We should have exactly consolidationThreshold utxos, // so this should trigger consolidation: @@ -73,11 +76,14 @@ export async function testBtcUtxoConsolidation(testContext: TestContext) { const consolidationBroadcastId = (await consolidationEventPromise).data.broadcastId; logger.debug(`Consolidation event is observed! Broadcast id: ${consolidationBroadcastId}`); - const broadcastSuccessPromise = observeEvent('bitcoinBroadcaster:BroadcastSuccess', { + const broadcastSuccessPromise = observeEvent(logger, 'bitcoinBroadcaster:BroadcastSuccess', { test: (event) => consolidationBroadcastId === event.data.broadcastId, }).event; - const feeDeficitPromise = observeEvent('bitcoinBroadcaster:TransactionFeeDeficitRecorded').event; + const feeDeficitPromise = observeEvent( + logger, + 'bitcoinBroadcaster:TransactionFeeDeficitRecorded', + ).event; logger.debug(`Waiting for broadcast ${consolidationBroadcastId} to succeed`); await broadcastSuccessPromise; diff --git a/bouncer/tests/create_and_delete_multiple_orders.ts b/bouncer/tests/create_and_delete_multiple_orders.ts index 2f6d95b3ba..e75cc21e63 100644 --- a/bouncer/tests/create_and_delete_multiple_orders.ts +++ b/bouncer/tests/create_and_delete_multiple_orders.ts @@ -40,16 +40,16 @@ export async function createAndDeleteMultipleOrders( await Promise.all([ // provide liquidity to LP_3 - depositLiquidity('Usdc', 10000, false, lpUri), - depositLiquidity('Eth', deposits.get('Eth')!, false, lpUri), - depositLiquidity('Dot', deposits.get('Dot')!, false, lpUri), - depositLiquidity('Btc', deposits.get('Btc')!, false, lpUri), - depositLiquidity('Flip', deposits.get('Flip')!, false, lpUri), - depositLiquidity('Usdt', deposits.get('Usdt')!, false, lpUri), - depositLiquidity('ArbEth', deposits.get('ArbEth')!, false, lpUri), - depositLiquidity('ArbUsdc', deposits.get('ArbUsdc')!, false, lpUri), - depositLiquidity('Sol', deposits.get('Sol')!, false, lpUri), - depositLiquidity('SolUsdc', deposits.get('SolUsdc')!, false, lpUri), + depositLiquidity(logger, 'Usdc', 10000, false, lpUri), + depositLiquidity(logger, 'Eth', deposits.get('Eth')!, false, lpUri), + depositLiquidity(logger, 'Dot', deposits.get('Dot')!, false, lpUri), + depositLiquidity(logger, 'Btc', deposits.get('Btc')!, false, lpUri), + depositLiquidity(logger, 'Flip', deposits.get('Flip')!, false, lpUri), + depositLiquidity(logger, 'Usdt', deposits.get('Usdt')!, false, lpUri), + depositLiquidity(logger, 'ArbEth', deposits.get('ArbEth')!, false, lpUri), + depositLiquidity(logger, 'ArbUsdc', deposits.get('ArbUsdc')!, false, lpUri), + depositLiquidity(logger, 'Sol', deposits.get('Sol')!, false, lpUri), + depositLiquidity(logger, 'SolUsdc', deposits.get('SolUsdc')!, false, lpUri), ]); // create a series of limit_order and save their info to delete them later on @@ -60,19 +60,19 @@ export async function createAndDeleteMultipleOrders( }[] = []; for (let i = 0; i < numberOfLimitOrders; i++) { - promises.push(limitOrder('Btc', 0.00000001, i, i, lpUri)); + promises.push(limitOrder(logger, 'Btc', 0.00000001, i, i, lpUri)); orderToDelete.push({ Limit: { base_asset: 'BTC', quote_asset: 'USDC', side: 'sell', id: i } }); } for (let i = 0; i < numberOfLimitOrders; i++) { - promises.push(limitOrder('Eth', 0.000000000000000001, i, i, lpUri)); + promises.push(limitOrder(logger, 'Eth', 0.000000000000000001, i, i, lpUri)); orderToDelete.push({ Limit: { base_asset: 'ETH', quote_asset: 'USDC', side: 'sell', id: i } }); } - promises.push(rangeOrder('Btc', 0.1, lpUri, 0)); + promises.push(rangeOrder(logger, 'Btc', 0.1, lpUri, 0)); orderToDelete.push({ Range: { base_asset: 'BTC', quote_asset: 'USDC', id: 0 }, }); - promises.push(rangeOrder('Eth', 0.01, lpUri, 0)); + promises.push(rangeOrder(logger, 'Eth', 0.01, lpUri, 0)); orderToDelete.push({ Range: { base_asset: 'ETH', quote_asset: 'USDC', id: 0 }, }); @@ -86,7 +86,7 @@ export async function createAndDeleteMultipleOrders( logger.debug(`Number of open orders: ${openOrders}`); logger.debug('Deleting opened orders...'); - const orderDeleteEvent = observeEvent('liquidityPools:RangeOrderUpdated', { + const orderDeleteEvent = observeEvent(logger, 'liquidityPools:RangeOrderUpdated', { test: (event) => event.data.lp === lp.address && event.data.baseAsset === 'Btc', }).event; await lpMutex.runExclusive(async () => { diff --git a/bouncer/tests/delta_based_ingress.ts b/bouncer/tests/delta_based_ingress.ts index 83a9c5769e..43c32fcffd 100644 --- a/bouncer/tests/delta_based_ingress.ts +++ b/bouncer/tests/delta_based_ingress.ts @@ -64,13 +64,14 @@ async function deltaBasedIngressTest( }; // Monitor swap events to make sure there is only one - let swapScheduledHandle = observeEvent('swapping:SwapScheduled', { + let swapScheduledHandle = observeEvent(logger, 'swapping:SwapScheduled', { test: (event) => handleSwapScheduled(event, amountFirstDeposit, 1), abortable: true, }); // Initiate swap from Solana const swapParams = await testSwap( + logger, sourceAsset, destAsset, undefined, @@ -100,14 +101,14 @@ async function deltaBasedIngressTest( // Start another swap doing another deposit to the same address const swapHandle = doPerformSwap( + logger.child({ tag: `[${sourceAsset}->${destAsset} DeltaBasedIngressSecondDeposit]` }), swapParams, - `[${sourceAsset}->${destAsset} DeltaBasedIngressSecondDeposit]`, undefined, undefined, amountSecondDeposit, ); - swapScheduledHandle = observeEvent('swapping:SwapScheduled', { + swapScheduledHandle = observeEvent(logger, 'swapping:SwapScheduled', { test: (event) => handleSwapScheduled(event, amountSecondDeposit, 2), abortable: true, }); diff --git a/bouncer/tests/double_deposit.ts b/bouncer/tests/double_deposit.ts index 3d4c929580..bab7c88ed2 100755 --- a/bouncer/tests/double_deposit.ts +++ b/bouncer/tests/double_deposit.ts @@ -26,15 +26,15 @@ export async function testDoubleDeposit(testContext: TestContext): Promise .signAndSend(lp); }); const ethIngressKey = ( - await observeEvent('liquidityProvider:LiquidityDepositAddressReady', { + await observeEvent(testContext.logger, 'liquidityProvider:LiquidityDepositAddressReady', { test: (event) => event.data.depositAddress.Eth, }).event ).data.depositAddress.Eth as string; testContext.debug('Eth ingress address: ' + ethIngressKey); await sleep(8000); // sleep for 8 seconds to give the engine a chance to start witnessing - await sendEvmNative('Ethereum', ethIngressKey, '10'); + await sendEvmNative(testContext.logger, 'Ethereum', ethIngressKey, '10'); - await observeEvent('assetBalances:AccountCredited').event; - await sendEvmNative('Ethereum', ethIngressKey, '10'); - await observeEvent('assetBalances:AccountCredited').event; + await observeEvent(testContext.logger, 'assetBalances:AccountCredited').event; + await sendEvmNative(testContext.logger, 'Ethereum', ethIngressKey, '10'); + await observeEvent(testContext.logger, 'assetBalances:AccountCredited').event; } diff --git a/bouncer/tests/evm_deposits.ts b/bouncer/tests/evm_deposits.ts index 8d9dacfe4a..a73d24e73a 100644 --- a/bouncer/tests/evm_deposits.ts +++ b/bouncer/tests/evm_deposits.ts @@ -24,6 +24,7 @@ import { send } from '../shared/send'; import { observeEvent, observeBadEvent } from '../shared/utils/substrate'; import { TestContext } from '../shared/utils/test_context'; +import { Logger, throwError } from '../shared/utils/logger'; const cfTesterAbi = await getCFTesterAbi(); @@ -33,6 +34,7 @@ async function testSuccessiveDepositEvm( testContext: TestContext, ) { const swapParams = await testSwap( + testContext.logger, sourceAsset, destAsset, undefined, @@ -44,7 +46,10 @@ async function testSuccessiveDepositEvm( // Check the Deposit contract is deployed. It is assumed that the funds are fetched immediately. await observeFetch(sourceAsset, swapParams.depositAddress); - await doPerformSwap(swapParams, `[${sourceAsset}->${destAsset} EvmDepositTestSecondDeposit]`); + await doPerformSwap( + testContext.logger.child({ tag: `[${sourceAsset}->${destAsset} EvmDepositTestSecondDeposit]` }), + swapParams, + ); } async function testNoDuplicateWitnessing( @@ -53,6 +58,7 @@ async function testNoDuplicateWitnessing( testContext: TestContext, ) { const swapParams = await testSwap( + testContext.logger, sourceAsset, destAsset, undefined, @@ -62,7 +68,7 @@ async function testNoDuplicateWitnessing( ); // Check the Deposit contract is deployed. It is assumed that the funds are fetched immediately. - const observingSwapScheduled = observeBadEvent('swapping:SwapScheduled', { + const observingSwapScheduled = observeBadEvent(testContext.logger, 'swapping:SwapScheduled', { test: (event) => { if (typeof event.data.origin === 'object' && 'DepositChannel' in event.data.origin) { const channelMatches = @@ -85,11 +91,12 @@ async function testNoDuplicateWitnessing( // Not supporting Btc to avoid adding more unnecessary complexity with address encoding. async function testTxMultipleVaultSwaps( + parentLogger: Logger, sourceAsset: Asset, destAsset: Asset, - testContext: TestContext, ) { - const { destAddress, tag } = await prepareSwap(sourceAsset, destAsset); + const { destAddress, tag } = await prepareSwap(parentLogger, sourceAsset, destAsset); + const logger = parentLogger.child({ tag }); const web3 = new Web3(getEvmEndpoint(chainFromAsset(sourceAsset))); @@ -113,6 +120,7 @@ async function testTxMultipleVaultSwaps( ) .encodeABI(); const receipt = await signAndSendTxEvm( + logger, chainFromAsset(sourceAsset), cfTesterAddress, (amount * BigInt(numSwaps)).toString(), @@ -120,7 +128,7 @@ async function testTxMultipleVaultSwaps( ); let eventCounter = 0; - const observingEvent = observeEvent('swapping:SwapRequested', { + const observingEvent = observeEvent(logger, 'swapping:SwapRequested', { test: (event) => { if ( typeof event.data.origin === 'object' && @@ -128,7 +136,7 @@ async function testTxMultipleVaultSwaps( event.data.origin.Vault.txId.Evm === receipt.transactionHash ) { if (++eventCounter > 1) { - throw new Error('Multiple swap scheduled events detected'); + throwError(logger, new Error('Multiple swap scheduled events detected')); } } return false; @@ -139,34 +147,36 @@ async function testTxMultipleVaultSwaps( while (eventCounter === 0) { await sleep(2000); } - testContext.debug(`${tag} Successfully observed event: swapping: SwapScheduled`); - // Wait some more time after the first event to ensure another one is not emited + // Wait some more time after the first event to ensure another one is not emitted await sleep(30000); observingEvent.stop(); await observingEvent.event; } -async function testDoubleDeposit(sourceAsset: Asset, destAsset: Asset, _testContext: TestContext) { +async function testDoubleDeposit(parentLogger: Logger, sourceAsset: Asset, destAsset: Asset) { const { destAddress, tag } = await prepareSwap( + parentLogger, sourceAsset, destAsset, undefined, undefined, - ' EvmDoubleDepositTest', + 'EvmDoubleDepositTest', ); - const swapParams = await requestNewSwap(sourceAsset, destAsset, destAddress, tag); + const logger = parentLogger.child({ tag }); + const swapParams = await requestNewSwap(logger, sourceAsset, destAsset, destAddress); { const swapRequestedHandle = observeSwapRequested( + logger, sourceAsset, destAsset, { type: TransactionOrigin.DepositChannel, channelId: swapParams.channelId }, SwapRequestType.Regular, ); - await send(sourceAsset, swapParams.depositAddress, defaultAssetAmounts(sourceAsset)); + await send(logger, sourceAsset, swapParams.depositAddress, defaultAssetAmounts(sourceAsset)); await swapRequestedHandle; } @@ -174,13 +184,14 @@ async function testDoubleDeposit(sourceAsset: Asset, destAsset: Asset, _testCont // should be scheduled when we deposit again. { const swapRequestedHandle = observeSwapRequested( + logger, sourceAsset, destAsset, { type: TransactionOrigin.DepositChannel, channelId: swapParams.channelId }, SwapRequestType.Regular, ); - await send(sourceAsset, swapParams.depositAddress, defaultAssetAmounts(sourceAsset)); + await send(logger, sourceAsset, swapParams.depositAddress, defaultAssetAmounts(sourceAsset)); await swapRequestedHandle; } } @@ -205,17 +216,17 @@ export async function testEvmDeposits(testContext: TestContext) { ]); const multipleTxSwapsTest = Promise.all([ - testTxMultipleVaultSwaps('Eth', 'Dot', testContext), - testTxMultipleVaultSwaps('Eth', 'Flip', testContext), - testTxMultipleVaultSwaps('ArbEth', 'Dot', testContext), - testTxMultipleVaultSwaps('ArbEth', 'Flip', testContext), + testTxMultipleVaultSwaps(testContext.logger, 'Eth', 'Dot'), + testTxMultipleVaultSwaps(testContext.logger, 'Eth', 'Flip'), + testTxMultipleVaultSwaps(testContext.logger, 'ArbEth', 'Dot'), + testTxMultipleVaultSwaps(testContext.logger, 'ArbEth', 'Flip'), ]); const doubleDepositTests = Promise.all([ - testDoubleDeposit('Eth', 'Dot', testContext), - testDoubleDeposit('Usdc', 'Flip', testContext), - testDoubleDeposit('ArbEth', 'Dot', testContext), - testDoubleDeposit('ArbUsdc', 'Btc', testContext), + testDoubleDeposit(testContext.logger, 'Eth', 'Dot'), + testDoubleDeposit(testContext.logger, 'Usdc', 'Flip'), + testDoubleDeposit(testContext.logger, 'ArbEth', 'Dot'), + testDoubleDeposit(testContext.logger, 'ArbUsdc', 'Btc'), ]); await Promise.all([ diff --git a/bouncer/tests/fill_or_kill.ts b/bouncer/tests/fill_or_kill.ts index 74fc87990d..2b50ab6195 100644 --- a/bouncer/tests/fill_or_kill.ts +++ b/bouncer/tests/fill_or_kill.ts @@ -20,11 +20,12 @@ import { Logger } from '../shared/utils/logger'; /// Do a swap with unrealistic minimum price so it gets refunded. async function testMinPriceRefund( - logger: Logger, + parentLogger: Logger, inputAsset: Asset, amount: number, swapViaVault = false, ) { + const logger = parentLogger.child({ tag: `FoK_${inputAsset}_${amount}` }); const destAsset = inputAsset === Assets.Usdc ? Assets.Flip : Assets.Usdc; const refundAddress = await newAddress(inputAsset, randomBytes(32).toString('hex')); const destAddress = await newAddress(destAsset, randomBytes(32).toString('hex')); @@ -49,18 +50,18 @@ async function testMinPriceRefund( if (!swapViaVault) { logger.debug(`Requesting swap from ${inputAsset} to ${destAsset} with unrealistic min price`); const swapRequest = await requestNewSwap( + logger, inputAsset, destAsset, destAddress, - 'FoK_Test', undefined, // messageMetadata 0, // brokerCommissionBps - false, // log 0, // boostFeeBps refundParameters, ); const depositAddress = swapRequest.depositAddress; swapRequestedHandle = observeSwapRequested( + logger, inputAsset, destAsset, { type: TransactionOrigin.DepositChannel, channelId: swapRequest.channelId }, @@ -68,7 +69,7 @@ async function testMinPriceRefund( ); // Deposit the asset - await send(inputAsset, depositAddress, amount.toString()); + await send(logger, inputAsset, depositAddress, amount.toString()); logger.debug(`Sent ${amount} ${inputAsset} to ${depositAddress}`); } else { logger.debug( @@ -76,6 +77,7 @@ async function testMinPriceRefund( ); const { transactionId } = await executeVaultSwap( + logger, inputAsset, destAsset, destAddress, @@ -86,6 +88,7 @@ async function testMinPriceRefund( ); swapRequestedHandle = observeSwapRequested( + logger, inputAsset, destAsset, transactionId, @@ -97,7 +100,7 @@ async function testMinPriceRefund( const swapRequestId = Number(swapRequestedEvent.data.swapRequestId.replaceAll(',', '')); logger.debug(`${inputAsset} swap requested, swapRequestId: ${swapRequestId}`); - const observeSwapExecuted = observeEvent(`swapping:SwapExecuted`, { + const observeSwapExecuted = observeEvent(logger, `swapping:SwapExecuted`, { test: (event) => Number(event.data.swapRequestId.replaceAll(',', '')) === swapRequestId, historicalCheckBlocks: 10, }).event; @@ -105,7 +108,7 @@ async function testMinPriceRefund( // Wait for the swap to execute or get refunded const executeOrRefund = await Promise.race([ observeSwapExecuted, - observeBalanceIncrease(inputAsset, refundAddress, refundBalanceBefore), + observeBalanceIncrease(logger, inputAsset, refundAddress, refundBalanceBefore), ]); if (typeof executeOrRefund !== 'number') { diff --git a/bouncer/tests/fund_redeem.ts b/bouncer/tests/fund_redeem.ts index cdc7a237f9..06a98c1ec5 100644 --- a/bouncer/tests/fund_redeem.ts +++ b/bouncer/tests/fund_redeem.ts @@ -20,17 +20,17 @@ const gasErrorMargin = 0.1; /// Redeems the flip and observed the balance increase async function redeemAndObserve( + logger: Logger, seed: string, redeemEthAddress: HexString, redeemAmount: RedeemAmount, - logger: Logger, ): Promise { const initBalance = await getBalance('Flip', redeemEthAddress); logger.debug(`Initial ERC20-Flip balance: ${initBalance}`); - await redeemFlip(seed, redeemEthAddress, redeemAmount); + await redeemFlip(logger, seed, redeemEthAddress, redeemAmount); - const newBalance = await observeBalanceIncrease('Flip', redeemEthAddress, initBalance); + const newBalance = await observeBalanceIncrease(logger, 'Flip', redeemEthAddress, initBalance); const balanceIncrease = newBalance - parseFloat(initBalance); logger.debug( `Redemption success! New balance: ${newBalance.toString()}, Increase: ${balanceIncrease}`, @@ -59,17 +59,17 @@ async function main(logger: Logger, providedSeed?: string) { logger.debug(`Eth Redeem address: ${redeemEthAddress}`); // Fund the SC address for the tests - await fundFlip(redeemSCAddress, fundAmount.toString()); + await fundFlip(logger, redeemSCAddress, fundAmount.toString()); // Test redeeming an exact amount with a portion of the funded flip const exactAmount = fundAmount / 4; const exactRedeemAmount = { Exact: exactAmount.toString() }; logger.debug(`Testing redeem exact amount: ${exactRedeemAmount.Exact}`); const redeemedExact = await redeemAndObserve( + logger, seed, redeemEthAddress as HexString, exactRedeemAmount, - logger, ); logger.debug(`Expected balance increase amount: ${exactAmount}`); assert.strictEqual( @@ -81,7 +81,7 @@ async function main(logger: Logger, providedSeed?: string) { // Test redeeming the rest of the flip with a 'Max' redeem amount logger.debug(`Testing redeem all`); - const redeemedAll = await redeemAndObserve(seed, redeemEthAddress as HexString, 'Max', logger); + const redeemedAll = await redeemAndObserve(logger, seed, redeemEthAddress as HexString, 'Max'); // We expect to redeem the entire amount minus the exact amount redeemed above + tax & gas for both redemptions const expectedRedeemAllAmount = fundAmount - redeemedExact - redemptionTaxAmount * 2; assert( diff --git a/bouncer/tests/gaslimit_ccm.ts b/bouncer/tests/gaslimit_ccm.ts index 330648e2a3..54cbbf9a2b 100644 --- a/bouncer/tests/gaslimit_ccm.ts +++ b/bouncer/tests/gaslimit_ccm.ts @@ -58,12 +58,12 @@ function getChainMinFee(chain: Chain): number { } } -async function getChainFees(chain: Chain) { +async function getChainFees(logger: Logger, chain: Chain) { let baseFee = 0; let priorityFee = 0; const trackedData = ( - await observeEvent(`${chain.toLowerCase()}ChainTracking:ChainStateUpdated`).event + await observeEvent(logger, `${chain.toLowerCase()}ChainTracking:ChainStateUpdated`).event ).data.newChainState.trackedData; switch (chain) { @@ -87,7 +87,7 @@ async function getChainFees(chain: Chain) { } async function executeAndTrackCcmSwap( - logger: Logger, + parentLogger: Logger, sourceAsset: Asset, destAsset: Asset, messageMetadata: CcmDepositMetadata, @@ -99,32 +99,35 @@ async function executeAndTrackCcmSwap( } const { destAddress, tag } = await prepareSwap( + parentLogger, sourceAsset, destAsset, undefined, messageMetadata, `GasLimit${testTag || ''}`, ); + const logger = parentLogger.child({ tag }); const { depositAddress, channelId } = await requestNewSwap( + logger, sourceAsset, destAsset, destAddress, - tag, messageMetadata, ); const swapRequestedHandle = observeSwapRequested( + logger, sourceAsset, destAsset, { type: TransactionOrigin.DepositChannel, channelId }, SwapRequestType.Regular, ); - await send(sourceAsset, depositAddress); + await send(logger, sourceAsset, depositAddress); const swapRequestId = Number((await swapRequestedHandle).data.swapRequestId.replaceAll(',', '')); // Find all of the swap events const egressId = ( - await observeEvent('swapping:SwapEgressScheduled', { + await observeEvent(logger, 'swapping:SwapEgressScheduled', { test: (event) => Number(event.data.swapRequestId.replaceAll(',', '')) === swapRequestId, historicalCheckBlocks: CHECK_PAST_BLOCKS_FOR_EVENTS, }).event @@ -132,7 +135,7 @@ async function executeAndTrackCcmSwap( logger.debug(`${tag} Found egressId: ${egressId}`); const broadcastId = ( - await observeEvent(`${destChain.toLowerCase()}IngressEgress:CcmBroadcastRequested`, { + await observeEvent(logger, `${destChain.toLowerCase()}IngressEgress:CcmBroadcastRequested`, { test: (event) => event.data.egressId[0] === egressId[0] && event.data.egressId[1] === egressId[1], historicalCheckBlocks: CHECK_PAST_BLOCKS_FOR_EVENTS, @@ -141,10 +144,14 @@ async function executeAndTrackCcmSwap( logger.debug(`${tag} Found broadcastId: ${broadcastId}`); const txPayload = ( - await observeEvent(`${destChain.toLowerCase()}Broadcaster:TransactionBroadcastRequest`, { - test: (event) => event.data.broadcastId === broadcastId, - historicalCheckBlocks: CHECK_PAST_BLOCKS_FOR_EVENTS, - }).event + await observeEvent( + logger, + `${destChain.toLowerCase()}Broadcaster:TransactionBroadcastRequest`, + { + test: (event) => event.data.broadcastId === broadcastId, + historicalCheckBlocks: CHECK_PAST_BLOCKS_FOR_EVENTS, + }, + ).event ).data.transactionPayload; logger.debug(`${tag} Found txPayload: ${txPayload}`); @@ -170,7 +177,7 @@ async function testGasLimitSwapToSolana(logger: Logger, sourceAsset: Asset, dest logger.debug(`${tag} Finished tracking events`); - const { priorityFee: computePrice } = await getChainFees('Solana'); + const { priorityFee: computePrice } = await getChainFees(logger, 'Solana'); if (computePrice === 0) { throw new Error('Compute price should not be 0'); @@ -195,6 +202,7 @@ async function testGasLimitSwapToSolana(logger: Logger, sourceAsset: Asset, dest throw new Error(`${tag} Transaction should not have reverted!`); } const feeDeficitHandle = observeEvent( + logger, `${destChain.toLowerCase()}Broadcaster:TransactionFeeDeficitRecorded`, { test: (event) => Number(event.data.amount.replace(/,/g, '')) === totalFee }, ); @@ -209,7 +217,7 @@ async function testGasLimitSwapToSolana(logger: Logger, sourceAsset: Asset, dest const usedGasConsumptionAmount = new Set(); async function testGasLimitSwapToEvm( - logger: Logger, + parentLogger: Logger, sourceAsset: Asset, destAsset: Asset, abortTest: boolean = false, @@ -257,19 +265,20 @@ async function testGasLimitSwapToEvm( const testTag = abortTest ? `InsufficientGas` : ''; const { tag, destAddress, broadcastId, txPayload } = await executeAndTrackCcmSwap( - logger, + parentLogger, sourceAsset, destAsset, ccmMetadata, testTag, ); + const logger = parentLogger.child({ tag }); logger.debug(`${tag} Finished tracking events`); const maxFeePerGas = Number(txPayload.maxFeePerGas.replace(/,/g, '')); const gasLimitBudget = Number(txPayload.gasLimit.replace(/,/g, '')); logger.debug( - `${tag} Expecting broadcast ${abortTest ? 'abort' : 'success'}. Broadcast gas budget: ${gasLimitBudget}, user gasBudget ${ccmMetadata.gasBudget} cfTester gasConsumption ${gasConsumption}`, + `Expecting broadcast ${abortTest ? 'abort' : 'success'}. Broadcast gas budget: ${gasLimitBudget}, user gasBudget ${ccmMetadata.gasBudget} cfTester gasConsumption ${gasConsumption}`, ); if (abortTest) { @@ -288,33 +297,33 @@ async function testGasLimitSwapToEvm( () => stopObservingCcmReceived, ).then((event) => { if (event !== undefined) { - throw new Error(`${tag} CCM event emitted. Transaction should not have been broadcasted!`); + throw new Error(`$CCM event emitted. Transaction should not have been broadcasted!`); } }); - await observeEvent(`${destChain.toLowerCase()}Broadcaster:BroadcastAborted`, { + await observeEvent(logger, `${destChain.toLowerCase()}Broadcaster:BroadcastAborted`, { test: (event) => event.data.broadcastId === broadcastId, }).event; stopObservingCcmReceived = true; - logger.debug(`${tag} Broadcast Aborted found! broadcastId: ${broadcastId}`); + logger.debug(`Broadcast Aborted found! broadcastId: ${broadcastId}`); } else { // Check that broadcast is not aborted const observeBroadcastFailure = observeBadEvent( + logger, `${destChain.toLowerCase()}Broadcaster:BroadcastAborted`, { test: (event) => { const aborted = event.data.broadcastId === broadcastId; if (aborted) { throw new Error( - `${tag} FAILURE! Broadcast Aborted unexpected! broadcastId: ${event.data.broadcastId}. Gas budget: ${gasLimitBudget}`, + `FAILURE! Broadcast Aborted unexpected! broadcastId: ${event.data.broadcastId}. Gas budget: ${gasLimitBudget}`, ); } return aborted; }, - label: testTag, }, ); - logger.debug(`${tag} Waiting for CCM event...`); + logger.debug(`Waiting for CCM event...`); // Expecting success const ccmReceived = await observeCcmReceived(sourceAsset, destAsset, destAddress, ccmMetadata); @@ -322,7 +331,7 @@ async function testGasLimitSwapToEvm( throw new Error(`${tag} CCM event emitted. Gas consumed is less than expected!`); } - logger.debug(`${tag} CCM event emitted!`); + logger.debug(`$CCM event emitted!`); // Stop listening for broadcast failure await observeBroadcastFailure.stop(); @@ -334,6 +343,7 @@ async function testGasLimitSwapToEvm( const totalFee = gasUsed * Number(gasPrice); const feeDeficitHandle = observeEvent( + logger, `${destChain.toLowerCase()}Broadcaster:TransactionFeeDeficitRecorded`, { test: (event) => Number(event.data.amount.replace(/,/g, '')) === totalFee }, ); @@ -362,11 +372,11 @@ async function testEvmInsufficientGas(logger: Logger, sourceAsset: Asset, destAs // Spamming to raise Ethereum's fee, otherwise it will get stuck at almost zero fee (~7 wei) let spam = true; -async function spamChain(chain: Chain) { +async function spamChain(logger: Logger, chain: Chain) { switch (chain) { case 'Ethereum': case 'Arbitrum': - spamEvm('Ethereum', 500, () => spam); + spamEvm(logger, 'Ethereum', 500, () => spam); break; default: throw new Error(`Chain ${chain} is not supported for CCM`); @@ -375,21 +385,21 @@ async function spamChain(chain: Chain) { export async function testGasLimitCcmSwaps(testContext: TestContext) { const logger = testContext.logger; - const feeDeficitRefused = observeBadEvent(':TransactionFeeDeficitRefused', {}); - testContext.debug('Spamming chains to increase fees...'); + const feeDeficitRefused = observeBadEvent(logger, ':TransactionFeeDeficitRefused', {}); + logger.debug('Spamming chains to increase fees...'); // No need to spam Solana since we are hardcoding the priority fees on the SC // and the chain "base fee" don't increase anyway.. - const spammingEth = spamChain('Ethereum'); - const spammingArb = spamChain('Arbitrum'); + const spammingEth = spamChain(logger, 'Ethereum'); + const spammingArb = spamChain(logger, 'Arbitrum'); // Wait for the fees to increase to the stable expected amount let i = 0; const ethMinPriorityFee = getChainMinFee('Ethereum'); const arbMinBaseFee = getChainMinFee('Arbitrum'); while ( - (await getChainFees('Ethereum')).priorityFee < ethMinPriorityFee || - (await getChainFees('Arbitrum')).baseFee < arbMinBaseFee + (await getChainFees(logger, 'Ethereum')).priorityFee < ethMinPriorityFee || + (await getChainFees(logger, 'Arbitrum')).baseFee < arbMinBaseFee ) { if (++i > LOOP_TIMEOUT) { spam = false; diff --git a/bouncer/tests/legacy_vault_swap.ts b/bouncer/tests/legacy_vault_swap.ts index ec06537bd2..dc0b513c4b 100644 --- a/bouncer/tests/legacy_vault_swap.ts +++ b/bouncer/tests/legacy_vault_swap.ts @@ -52,7 +52,7 @@ async function legacyEvmVaultSwap( (await getEvmVaultAbi()) as any, vaultAddress, ); - const evmWallet = await createEvmWalletAndFund(sourceAsset); + const evmWallet = await createEvmWalletAndFund(logger, sourceAsset); const cfParametersList = ['', '0x', 'deadbeef', '0xdeadbeef', 'deadc0de', '0xdeadc0de']; const cfParameters = Math.floor(Math.random() * cfParametersList.length); @@ -128,6 +128,7 @@ async function legacyEvmVaultSwap( // Look after Swap Requested of data.origin.Vault.tx_hash const swapRequestedHandle = observeSwapRequested( + logger, sourceAsset, destAsset, { type: TransactionOrigin.VaultSwapEvm, txHash: receipt.transactionHash }, @@ -138,17 +139,17 @@ async function legacyEvmVaultSwap( logger.debug(`${sourceAsset} swap via vault, swapRequestId: ${swapRequestId}`); // Wait for the swap to complete - await observeEvent(`swapping:SwapRequestCompleted`, { + await observeEvent(logger, `swapping:SwapRequestCompleted`, { test: (event) => Number(event.data.swapRequestId.replaceAll(',', '')) === swapRequestId, }).event; - await observeEvent(`swapping:SwapExecuted`, { + await observeEvent(logger, `swapping:SwapExecuted`, { test: (event) => Number(event.data.swapRequestId.replaceAll(',', '')) === swapRequestId, historicalCheckBlocks: 10, }).event; logger.debug(`swapRequestId: ${swapRequestId} executed. Waiting for balance to increase.`); - await observeBalanceIncrease(destAsset, destAddress, destBalanceBefore); + await observeBalanceIncrease(logger, destAsset, destAddress, destBalanceBefore); logger.debug(`swapRequestId: ${swapRequestId} - swap success`); } diff --git a/bouncer/tests/lp_api_test.ts b/bouncer/tests/lp_api_test.ts index b8500e500f..40f4ba82ba 100644 --- a/bouncer/tests/lp_api_test.ts +++ b/bouncer/tests/lp_api_test.ts @@ -22,6 +22,7 @@ import { sendEvmNative } from '../shared/send_evm'; import { getBalance } from '../shared/get_balance'; import { getChainflipApi, observeEvent } from '../shared/utils/substrate'; import { TestContext } from '../shared/utils/test_context'; +import { Logger, loggerChild } from '../shared/utils/logger'; type RpcAsset = { asset: string; @@ -40,18 +41,18 @@ const testAssetAmount = parseInt( const amountToProvide = testAmount * 50; // Provide plenty of the asset for the tests const testAddress = '0x1594300cbd587694affd70c933b9ee9155b186d9'; -async function provideLiquidityAndTestAssetBalances() { +async function provideLiquidityAndTestAssetBalances(logger: Logger) { const fineAmountToProvide = parseInt( amountToFineAmount(amountToProvide.toString(), assetDecimals('Eth')), ); // We have to wait finalization here because the LP API server is using a finalized block stream (This may change in PRO-777 PR#3986) - await depositLiquidity(testAsset, amountToProvide, true, '//LP_API'); + await depositLiquidity(logger, testAsset, amountToProvide, true, '//LP_API'); // Wait for the LP API to get the balance update, just incase it was slower than us to see the event. let retryCount = 0; let ethBalance = 0; do { - const balances = await lpApiRpc(`lp_asset_balances`, []); + const balances = await lpApiRpc(logger, `lp_asset_balances`, []); ethBalance = parseInt(balances.Ethereum.Eth); retryCount++; if (retryCount > 14) { @@ -65,15 +66,17 @@ async function provideLiquidityAndTestAssetBalances() { } while (ethBalance < fineAmountToProvide); } -async function testRegisterLiquidityRefundAddress() { +async function testRegisterLiquidityRefundAddress(parentLogger: Logger) { + const logger = loggerChild(parentLogger, 'testRegisterLiquidityRefundAddress'); const observeRefundAddressRegisteredEvent = observeEvent( + logger, 'liquidityProvider:LiquidityRefundAddressRegistered', { test: (event) => event.data.address.Eth === testAddress, }, ); - const registerRefundAddress = await lpApiRpc(`lp_register_liquidity_refund_address`, [ + const registerRefundAddress = await lpApiRpc(logger, `lp_register_liquidity_refund_address`, [ 'Ethereum', testAddress, ]); @@ -85,8 +88,9 @@ async function testRegisterLiquidityRefundAddress() { // TODO: Check that the correct address is now set on the SC } -async function testLiquidityDeposit() { +async function testLiquidityDeposit(logger: Logger) { const observeLiquidityDepositAddressReadyEvent = observeEvent( + logger, 'liquidityProvider:LiquidityDepositAddressReady', { test: (event) => event.data.depositAddress.Eth, @@ -94,7 +98,7 @@ async function testLiquidityDeposit() { ).event; const liquidityDepositAddress = ( - await lpApiRpc(`lp_liquidity_deposit`, [testRpcAsset, 'InBlock']) + await lpApiRpc(logger, `lp_liquidity_deposit`, [testRpcAsset, 'InBlock']) ).tx_details.response; const liquidityDepositEvent = await observeLiquidityDepositAddressReadyEvent; @@ -109,7 +113,7 @@ async function testLiquidityDeposit() { ); // Send funds to the deposit address and watch for deposit event - const observeAccountCreditedEvent = observeEvent('assetBalances:AccountCredited', { + const observeAccountCreditedEvent = observeEvent(logger, 'assetBalances:AccountCredited', { test: (event) => event.data.asset === testAsset && isWithinOnePercent( @@ -117,14 +121,19 @@ async function testLiquidityDeposit() { BigInt(testAssetAmount), ), }).event; - await sendEvmNative(chainFromAsset(testAsset), liquidityDepositAddress, String(testAmount)); + await sendEvmNative( + logger, + chainFromAsset(testAsset), + liquidityDepositAddress, + String(testAmount), + ); await observeAccountCreditedEvent; } -async function testWithdrawAsset() { +async function testWithdrawAsset(logger: Logger) { const oldBalance = await getBalance(testAsset, testAddress); - const result = await lpApiRpc(`lp_withdraw_asset`, [ + const result = await lpApiRpc(logger, `lp_withdraw_asset`, [ testAssetAmount, testRpcAsset, testAddress, @@ -135,10 +144,10 @@ async function testWithdrawAsset() { assert.strictEqual(chain, testRpcAsset.chain, `Unexpected withdraw asset result`); assert(egressId > 0, `Unexpected egressId: ${egressId}`); - await observeBalanceIncrease(testAsset, testAddress, oldBalance); + await observeBalanceIncrease(logger, testAsset, testAddress, oldBalance); } -async function testTransferAsset() { +async function testTransferAsset(logger: Logger) { await using chainflip = await getChainflipApi(); const amountToTransfer = testAssetAmount.toString(16); @@ -161,7 +170,7 @@ async function testTransferAsset() { const oldBalanceSource = await getLpBalance(sourceLpAccount.address); const oldBalanceDestination = await getLpBalance(destinationLpAccount.address); - const result = await lpApiRpc(`lp_transfer_asset`, [ + const result = await lpApiRpc(logger, `lp_transfer_asset`, [ amountToTransfer, testRpcAsset, destinationLpAccount.address, @@ -196,9 +205,9 @@ async function testTransferAsset() { ); } -async function testRegisterWithExistingLpAccount() { +async function testRegisterWithExistingLpAccount(logger: Logger) { try { - await lpApiRpc(`lp_register_account`, []); + await lpApiRpc(logger, `lp_register_account`, []); throw new Error(`Unexpected lp_register_account result`); // eslint-disable-next-line @typescript-eslint/no-explicit-any } catch (error: any) { @@ -211,7 +220,7 @@ async function testRegisterWithExistingLpAccount() { } /// Test lp_set_range_order and lp_update_range_order by minting, updating, and burning a range order. -async function testRangeOrder() { +async function testRangeOrder(logger: Logger) { const range = { start: 1, end: 2 }; const orderId = 74398; // Arbitrary order id so it does not interfere with other tests const zeroAssetAmounts = { @@ -222,7 +231,7 @@ async function testRangeOrder() { }; // Cleanup after any unfinished previous test so it does not interfere with this test - await lpApiRpc(`lp_set_range_order`, [ + await lpApiRpc(logger, `lp_set_range_order`, [ testRpcAsset, 'USDC', orderId, @@ -233,7 +242,7 @@ async function testRangeOrder() { // Mint a range order const mintRangeOrder = ( - await lpApiRpc(`lp_set_range_order`, [ + await lpApiRpc(logger, `lp_set_range_order`, [ testRpcAsset, 'USDC', orderId, @@ -255,7 +264,7 @@ async function testRangeOrder() { // Update the range order const updateRangeOrder = ( - await lpApiRpc(`lp_update_range_order`, [ + await lpApiRpc(logger, `lp_update_range_order`, [ testRpcAsset, 'USDC', orderId, @@ -285,7 +294,7 @@ async function testRangeOrder() { // Burn the range order const burnRangeOrder = ( - await lpApiRpc(`lp_set_range_order`, [ + await lpApiRpc(logger, `lp_set_range_order`, [ testRpcAsset, 'USDC', orderId, @@ -307,9 +316,9 @@ async function testRangeOrder() { assert.strictEqual(matchBurn, true, `Expected burn of range order to decrease liquidity to 0`); } -async function testGetOpenSwapChannels() { +async function testGetOpenSwapChannels(logger: Logger) { // TODO: Test with some SwapChannelInfo data - const openSwapChannels = await lpApiRpc(`lp_get_open_swap_channels`, []); + const openSwapChannels = await lpApiRpc(logger, `lp_get_open_swap_channels`, []); assert(openSwapChannels.ethereum, `Missing ethereum swap channel info`); assert(openSwapChannels.polkadot, `Missing polkadot swap channel info`); assert(openSwapChannels.bitcoin, `Missing bitcoin swap channel info`); @@ -317,16 +326,16 @@ async function testGetOpenSwapChannels() { /// Test lp_set_limit_order and lp_update_limit_order by minting, updating, and burning a limit order. -async function testLimitOrder() { +async function testLimitOrder(logger: Logger) { const orderId = 98432; // Arbitrary order id so it does not interfere with other tests const tick = 2; // Cleanup after any unfinished previous test so it does not interfere with this test - await lpApiRpc(`lp_set_limit_order`, [testRpcAsset, 'USDC', 'sell', orderId, tick, 0]); + await lpApiRpc(logger, `lp_set_limit_order`, [testRpcAsset, 'USDC', 'sell', orderId, tick, 0]); // Mint a limit order const mintLimitOrder = ( - await lpApiRpc(`lp_set_limit_order`, [ + await lpApiRpc(logger, `lp_set_limit_order`, [ testRpcAsset, 'USDC', 'sell', @@ -350,7 +359,7 @@ async function testLimitOrder() { // Update the limit order const updateLimitOrder = ( - await lpApiRpc(`lp_update_limit_order`, [ + await lpApiRpc(logger, `lp_update_limit_order`, [ testRpcAsset, 'USDC', 'sell', @@ -381,7 +390,7 @@ async function testLimitOrder() { // Burn the limit order const burnLimitOrder = ( - await lpApiRpc(`lp_set_limit_order`, [testRpcAsset, 'USDC', 'sell', orderId, tick, 0]) + await lpApiRpc(logger, `lp_set_limit_order`, [testRpcAsset, 'USDC', 'sell', orderId, tick, 0]) ).tx_details.response; assert(burnLimitOrder.length >= 1, `Empty burn limit order result`); @@ -399,19 +408,19 @@ async function testLimitOrder() { } /// Runs all of the LP commands via the LP API Json RPC Server that is running and checks that the returned data is as expected -export async function testLpApi(_testContext: TestContext) { +export async function testLpApi(testContext: TestContext) { // Provide the amount of liquidity needed for the tests - await provideLiquidityAndTestAssetBalances(); + await provideLiquidityAndTestAssetBalances(testContext.logger); await Promise.all([ - testRegisterLiquidityRefundAddress, - testLiquidityDeposit, - testWithdrawAsset, - testRegisterWithExistingLpAccount, - testRangeOrder, - testLimitOrder, - testGetOpenSwapChannels, + testRegisterLiquidityRefundAddress(testContext.logger), + testLiquidityDeposit(testContext.logger), + testWithdrawAsset(testContext.logger), + testRegisterWithExistingLpAccount(testContext.logger), + testRangeOrder(testContext.logger), + testLimitOrder(testContext.logger), + testGetOpenSwapChannels(testContext.logger), ]); - await testTransferAsset; + await testTransferAsset(testContext.logger); } diff --git a/bouncer/tests/minimum_deposit.ts b/bouncer/tests/minimum_deposit.ts index 5bb824d955..6c0a7c8486 100755 --- a/bouncer/tests/minimum_deposit.ts +++ b/bouncer/tests/minimum_deposit.ts @@ -6,21 +6,21 @@ import { TestContext } from '../shared/utils/test_context'; export async function testMinimumDeposit(testContext: TestContext) { const logger = testContext.logger; - await setMinimumDeposit('Dot', BigInt(200000000000)); + await setMinimumDeposit(logger, 'Dot', BigInt(200000000000)); logger.debug('Set minimum deposit to 20 DOT'); const depositAddress = ( - await requestNewSwap('Dot', 'Eth', '0xd92bd8c144b8edba742b07909c04f8b93d875d93') + await requestNewSwap(logger, 'Dot', 'Eth', '0xd92bd8c144b8edba742b07909c04f8b93d875d93') ).depositAddress; - const depositFailed = observeEvent(':DepositFailed'); + const depositFailed = observeEvent(logger, ':DepositFailed'); await sendDot(depositAddress, '19'); logger.debug('Sent 19 DOT'); await depositFailed.event; logger.debug('Deposit was ignored'); - const depositSuccess = observeEvent(':DepositFinalised'); + const depositSuccess = observeEvent(logger, ':DepositFinalised'); await sendDot(depositAddress, '21'); logger.debug('Sent 21 DOT'); await depositSuccess.event; logger.debug('Deposit was successful'); - await setMinimumDeposit('Dot', BigInt(0)); + await setMinimumDeposit(logger, 'Dot', BigInt(0)); logger.debug('Reset minimum deposit to 0 DOT'); } diff --git a/bouncer/tests/multiple_members_governance.ts b/bouncer/tests/multiple_members_governance.ts index 70a06690f8..247664cea9 100644 --- a/bouncer/tests/multiple_members_governance.ts +++ b/bouncer/tests/multiple_members_governance.ts @@ -31,7 +31,7 @@ async function addAliceToGovernance(logger: Logger) { await setGovernanceMembers(newMembers); - await observeEvent('governance:Executed').event; + await observeEvent(logger, 'governance:Executed').event; await tryUntilSuccess(async () => (await getGovernanceMembers()).length === 2, 3000, 10); @@ -47,12 +47,12 @@ async function submitWithMultipleGovernanceMembers(logger: Logger) { await using chainflip = await getChainflipApi(); - const proposalId = Number((await observeEvent('governance:Proposed').event).data); + const proposalId = Number((await observeEvent(logger, 'governance:Proposed').event).data); // Note that with two members, we need to approve with the other account: await chainflip.tx.governance.approve(proposalId).signAndSend(alice, { nonce: -1 }); - const executedProposalId = Number((await observeEvent('governance:Executed').event).data); + const executedProposalId = Number((await observeEvent(logger, 'governance:Executed').event).data); assert(proposalId === executedProposalId, 'Proposal Ids should match'); assert( diff --git a/bouncer/tests/polkadot_runtime_update.ts b/bouncer/tests/polkadot_runtime_update.ts index 5bf3d60f3f..63893893ac 100644 --- a/bouncer/tests/polkadot_runtime_update.ts +++ b/bouncer/tests/polkadot_runtime_update.ts @@ -10,7 +10,7 @@ import { specVersion, getNetworkRuntimeVersion } from '../shared/utils/spec_vers import { handleDispatchError, submitAndGetEvent } from '../shared/polkadot_utils'; import { testSwap } from '../shared/swapping'; import { observeEvent, observeBadEvent, getPolkadotApi } from '../shared/utils/substrate'; -import { Logger } from '../shared/utils/logger'; +import { Logger, loggerChild } from '../shared/utils/logger'; import { TestContext } from '../shared/utils/test_context'; // Note: This test only passes if there is more than one node in the network due to the polkadot runtime upgrade causing broadcast failures due to bad signatures. @@ -31,7 +31,7 @@ let swapsStarted = 0; /// Pushes a polkadot runtime update using the democracy pallet. /// preimage -> proposal -> vote -> democracy pass -> scheduler dispatch runtime update. -export async function pushPolkadotRuntimeUpdate(wasmPath: string, logger: Logger): Promise { +export async function pushPolkadotRuntimeUpdate(logger: Logger, wasmPath: string): Promise { await using polkadot = await getPolkadotApi(); logger.info('-- Pushing polkadot runtime update --'); @@ -70,7 +70,7 @@ export async function pushPolkadotRuntimeUpdate(wasmPath: string, logger: Logger } // Submit the proposal - const observeDemocracyStarted = observeEvent('democracy:Started', { + const observeDemocracyStarted = observeEvent(logger, 'democracy:Started', { chain: 'polkadot', }).event; const amount = amountToFineAmount(PROPOSAL_AMOUNT, assetDecimals('Dot')); @@ -87,16 +87,16 @@ export async function pushPolkadotRuntimeUpdate(wasmPath: string, logger: Logger await observeDemocracyStarted; // Vote for the proposal - const observeDemocracyPassed = observeEvent('democracy:Passed', { + const observeDemocracyPassed = observeEvent(logger, 'democracy:Passed', { chain: 'polkadot', }).event; - const observeDemocracyNotPassed = observeEvent('democracy:NotPassed', { + const observeDemocracyNotPassed = observeEvent(logger, 'democracy:NotPassed', { chain: 'polkadot', }).event; - const observeSchedulerDispatched = observeEvent('scheduler:Dispatched', { + const observeSchedulerDispatched = observeEvent(logger, 'scheduler:Dispatched', { chain: 'polkadot', }).event; - const observeCodeUpdated = observeEvent('system:CodeUpdated', { + const observeCodeUpdated = observeEvent(logger, 'system:CodeUpdated', { chain: 'polkadot', }).event; const vote = { Standard: { vote: true, balance: amount } }; @@ -140,7 +140,8 @@ export async function bumpAndBuildPolkadotRuntime(logger: Logger): Promise<[stri const projectPath = process.cwd(); // tmp/ is ignored in the bouncer .gitignore file. const workspacePath = path.join(projectPath, 'tmp/polkadot'); - const nextSpecVersion = (await getNetworkRuntimeVersion(polkadotEndpoint)).specVersion + 1; + const nextSpecVersion = + (await getNetworkRuntimeVersion(logger, polkadotEndpoint)).specVersion + 1; logger.debug('Current polkadot spec_version: ' + nextSpecVersion); // No need to compile if the version we need is the pre-compiled version. @@ -174,7 +175,7 @@ export async function bumpAndBuildPolkadotRuntime(logger: Logger): Promise<[stri logger.debug('Updating polkadot source'); execSync(`git pull`, { cwd: workspacePath }); - specVersion(`${workspacePath}/runtime/polkadot/src/lib.rs`, 'write', nextSpecVersion); + specVersion(logger, `${workspacePath}/runtime/polkadot/src/lib.rs`, 'write', nextSpecVersion); // Compile polkadot runtime logger.debug('Compiling polkadot...'); @@ -210,6 +211,7 @@ async function randomPolkadotSwap(testContext: TestContext): Promise { } await testSwap( + testContext.logger, sourceAsset, destAsset, undefined, @@ -217,14 +219,13 @@ async function randomPolkadotSwap(testContext: TestContext): Promise { testContext.swapContext, undefined, undefined, - false, ); swapsComplete++; testContext.debug(`Swap complete: (${swapsComplete}/${swapsStarted})`); } async function doPolkadotSwaps(testContext: TestContext): Promise { - const logger = testContext.logger.child({ module: 'doPolkadotSwaps' }); + const logger = loggerChild(testContext.logger, 'doPolkadotSwaps'); const startSwapInterval = 2000; logger.debug(`Running polkadot swaps, new random swap every ${startSwapInterval}ms`); while (!runtimeUpdatePushed) { @@ -248,9 +249,7 @@ export async function testPolkadotRuntimeUpdate(testContext: TestContext): Promi const [wasmPath, expectedSpecVersion] = await bumpAndBuildPolkadotRuntime(logger); // Monitor for the broadcast aborted event to help catch failed swaps - const broadcastAborted = observeBadEvent(':BroadcastAborted', { - label: 'Polkadot runtime upgrade', - }); + const broadcastAborted = observeBadEvent(logger, ':BroadcastAborted', {}); // Start some swaps const swapping = doPolkadotSwaps(testContext); @@ -260,10 +259,10 @@ export async function testPolkadotRuntimeUpdate(testContext: TestContext): Promi } // Submit the runtime update - await pushPolkadotRuntimeUpdate(wasmPath, logger); + await pushPolkadotRuntimeUpdate(logger, wasmPath); // Check the polkadot spec version has changed - const postUpgradeSpecVersion = await getNetworkRuntimeVersion(polkadotEndpoint); + const postUpgradeSpecVersion = await getNetworkRuntimeVersion(logger, polkadotEndpoint); if (postUpgradeSpecVersion.specVersion !== expectedSpecVersion) { throw new Error( `Polkadot runtime update failed. Currently at version ${postUpgradeSpecVersion.specVersion}, expected to be at ${expectedSpecVersion}`, diff --git a/bouncer/tests/rotates_through_btc_swap.ts b/bouncer/tests/rotates_through_btc_swap.ts index f2e66ba08c..cd5b40ec66 100755 --- a/bouncer/tests/rotates_through_btc_swap.ts +++ b/bouncer/tests/rotates_through_btc_swap.ts @@ -5,41 +5,41 @@ import { prepareSwap, testSwap } from '../shared/swapping'; import { TestContext } from '../shared/utils/test_context'; async function rotatesThroughBtcSwap(testContext: TestContext) { - const logger = testContext.logger; const sourceAsset = 'Btc'; const destAsset = 'Dot'; const { destAddress, tag } = await prepareSwap( + testContext.logger, sourceAsset, destAsset, undefined, undefined, 'through rotation', - true, testContext.swapContext, ); + const logger = testContext.logger.child({ tag }); logger.debug('Generated Dot address: ' + destAddress); - const swapParams = await requestNewSwap(sourceAsset, destAsset, destAddress, tag); + const swapParams = await requestNewSwap(logger, sourceAsset, destAsset, destAddress); await submitGovernanceExtrinsic((api) => api.tx.validator.forceRotation()); logger.info(`Vault rotation initiated. Awaiting new epoch.`); - await observeEvent('validator:NewEpoch').event; + await observeEvent(logger, 'validator:NewEpoch').event; logger.info('Vault rotated!'); - await doPerformSwap( - swapParams, - tag, - undefined, - undefined, - undefined, - true, - testContext.swapContext, - ); + await doPerformSwap(logger, swapParams, undefined, undefined, undefined, testContext.swapContext); } export async function testRotatesThroughBtcSwap(testContext: TestContext) { await rotatesThroughBtcSwap(testContext); - await testSwap('Dot', 'Btc', undefined, undefined, testContext.swapContext, 'after rotation'); + await testSwap( + testContext.logger, + 'Dot', + 'Btc', + undefined, + undefined, + testContext.swapContext, + 'after rotation', + ); } diff --git a/bouncer/tests/rotation_barrier.ts b/bouncer/tests/rotation_barrier.ts index a3818a1cbc..235d1858e9 100755 --- a/bouncer/tests/rotation_barrier.ts +++ b/bouncer/tests/rotation_barrier.ts @@ -1,4 +1,3 @@ -#!/usr/bin/env -S pnpm tsx import { submitGovernanceExtrinsic } from '../shared/cf_governance'; import { TestContext } from '../shared/utils/test_context'; import { testVaultSwap } from '../shared/swapping'; @@ -10,16 +9,16 @@ export async function testRotateAndSwap(testContext: TestContext) { // Wait for the activation key to be created and the activation key to be sent for signing testContext.info(`Vault rotation initiated`); - await observeEvent('evmThresholdSigner:KeygenSuccess').event; + await observeEvent(testContext.logger, 'evmThresholdSigner:KeygenSuccess').event; testContext.info(`Waiting for the bitcoin key handover`); - await observeEvent('bitcoinThresholdSigner:KeyHandoverSuccessReported').event; + await observeEvent(testContext.logger, 'bitcoinThresholdSigner:KeyHandoverSuccessReported').event; testContext.info(`Waiting for eth key activation transaction to be sent for signing`); - await observeEvent('evmThresholdSigner:ThresholdSignatureRequest').event; + await observeEvent(testContext.logger, 'evmThresholdSigner:ThresholdSignatureRequest').event; - const broadcastAborted = observeBadEvent(':BroadcastAborted', { label: 'Rotate and swap' }); + const broadcastAborted = observeBadEvent(testContext.logger, ':BroadcastAborted', {}); // Using Arbitrum as the ingress chain to make the swap as fast as possible - await testVaultSwap('ArbEth', 'Eth'); + await testVaultSwap(testContext.logger, 'ArbEth', 'Eth'); await broadcastAborted.stop(); } diff --git a/bouncer/tests/solana_vault_settings_governance.ts b/bouncer/tests/solana_vault_settings_governance.ts index 857ef15a3b..afd1deb03f 100755 --- a/bouncer/tests/solana_vault_settings_governance.ts +++ b/bouncer/tests/solana_vault_settings_governance.ts @@ -48,7 +48,7 @@ async function getTokenSupportedAccount() { return cfVaultProgram.account.supportedToken.fetch(vaultUsdcTokenSupportedAccount); } -async function submitNativeVaultSettingsGovernance(settings: VaultSwapSettings, logger: Logger) { +async function submitNativeVaultSettingsGovernance(logger: Logger, settings: VaultSwapSettings) { const { minNativeSwapAmount, maxDstAddressLen, @@ -71,7 +71,7 @@ async function submitNativeVaultSettingsGovernance(settings: VaultSwapSettings, ); } -async function submitTokenVaultSettingsGovernance(settings: VaultSwapSettings, logger: Logger) { +async function submitTokenVaultSettingsGovernance(logger: Logger, settings: VaultSwapSettings) { const { minTokenSwapAmount, tokenMintPubkey } = settings; logger.info('Submitting token vault settings via governance'); @@ -154,7 +154,7 @@ export async function testSolanaVaultSettingsGovernance(testContext: TestContext minTokenSwapAmount: settings.minTokenSwapAmount + 1, tokenMintPubkey: settings.tokenMintPubkey, }; - await submitNativeVaultSettingsGovernance(newSettings, testContext.logger); + await submitNativeVaultSettingsGovernance(testContext.logger, newSettings); // Only the native settings should have changed settings = { @@ -177,7 +177,7 @@ export async function testSolanaVaultSettingsGovernance(testContext: TestContext minTokenSwapAmount: settings.minTokenSwapAmount + 10, tokenMintPubkey: settings.tokenMintPubkey, } as VaultSwapSettings; - await submitTokenVaultSettingsGovernance(newSettings, testContext.logger); + await submitTokenVaultSettingsGovernance(testContext.logger, newSettings); // Only the token settings should have changed settings = { diff --git a/bouncer/tests/swap_after_temp_disconnecting_chains.ts b/bouncer/tests/swap_after_temp_disconnecting_chains.ts index 4d6f3c7de5..7d16d9b702 100755 --- a/bouncer/tests/swap_after_temp_disconnecting_chains.ts +++ b/bouncer/tests/swap_after_temp_disconnecting_chains.ts @@ -9,17 +9,21 @@ export async function testSwapAfterDisconnection(testContext: TestContext) { const allExternalNodes = ['bitcoin', 'geth']; await Promise.all( - allExternalNodes.map((container) => disconnectContainerFromNetwork(container, networkName)), + allExternalNodes.map((container) => + disconnectContainerFromNetwork(testContext.logger, container, networkName), + ), ); await sleep(10000); await Promise.all( - allExternalNodes.map((container) => connectContainerToNetwork(container, networkName)), + allExternalNodes.map((container) => + connectContainerToNetwork(testContext.logger, container, networkName), + ), ); await Promise.all([ - testSwap('Btc', 'Flip', undefined, undefined, testContext.swapContext), - testSwap('Eth', 'Usdc', undefined, undefined, testContext.swapContext), + testSwap(testContext.logger, 'Btc', 'Flip', undefined, undefined, testContext.swapContext), + testSwap(testContext.logger, 'Eth', 'Usdc', undefined, undefined, testContext.swapContext), ]); } diff --git a/bouncer/tests/swap_less_than_existential_deposit_dot.ts b/bouncer/tests/swap_less_than_existential_deposit_dot.ts index f7ef0e6558..49fb16b65a 100755 --- a/bouncer/tests/swap_less_than_existential_deposit_dot.ts +++ b/bouncer/tests/swap_less_than_existential_deposit_dot.ts @@ -6,8 +6,8 @@ import { getSwapRate, newAddress } from '../shared/utils'; const DOT_EXISTENTIAL_DEPOSIT = 1; export async function swapLessThanED(textContext: TestContext) { - const logger = textContext.logger; const tag = `Usdc -> Dot`; + const logger = textContext.logger.child({ tag }); // we will try to swap with 5 Usdc and check if the expected output is low enough // otherwise we'll keep reducing the amount @@ -20,21 +20,21 @@ export async function swapLessThanED(textContext: TestContext) { inputAmount = (parseFloat(inputAmount) / 2).toString(); outputAmount = await getSwapRate('Usdc', 'Dot', inputAmount); } - logger.debug(`${tag} Input amount: ${inputAmount} Usdc`); - logger.debug(`${tag} Approximate expected output amount: ${outputAmount} Dot`); + logger.debug(`Input amount: ${inputAmount} Usdc`); + logger.debug(`Approximate expected output amount: ${outputAmount} Dot`); // we want to be sure to have an address with 0 balance, hence we create a new one every time const address = await newAddress( 'Dot', '!testing less than ED output for dot swaps!' + inputAmount + outputAmount, ); - logger.debug(`${tag} Generated Dot address: ${address}`); + logger.debug(`Generated Dot address: ${address}`); - await performAndTrackSwap('Usdc', 'Dot', address, inputAmount, tag); + await performAndTrackSwap(logger, 'Usdc', 'Dot', address, inputAmount); // if for some reason the balance after swapping is > 0 it means that the output was larger than // ED, so we'll retry the test with a lower input if (parseFloat(await getDotBalance(address)) > 0) { - logger.debug(`${tag}, swap output was more than ED, retrying with less...`); + logger.debug(`Swap output was more than ED, retrying with less...`); inputAmount = (parseFloat(inputAmount) / 3).toString(); } else { retry = false; diff --git a/bouncer/tests/vault_swap_fee_collection.ts b/bouncer/tests/vault_swap_fee_collection.ts index ab62e1303d..95a4e5c930 100644 --- a/bouncer/tests/vault_swap_fee_collection.ts +++ b/bouncer/tests/vault_swap_fee_collection.ts @@ -23,10 +23,10 @@ import { Logger } from '../shared/utils/logger'; const commissionBps = 100; async function testWithdrawCollectedAffiliateFees( + logger: Logger, broker: KeyringPair, affiliateAccountId: string, withdrawAddress: string, - logger: Logger, ) { const chainflip = await getChainflipApi(); @@ -34,15 +34,15 @@ async function testWithdrawCollectedAffiliateFees( let success = false; logger.info('Starting withdraw collected affiliate fees test...'); - logger.info('Affiliate account ID:', affiliateAccountId); - logger.info('Withdraw address:', withdrawAddress); + logger.debug('Affiliate account ID:', affiliateAccountId); + logger.debug('Withdraw address:', withdrawAddress); await chainflip.tx.swapping .affiliateWithdrawalRequest(affiliateAccountId) .signAndSend(broker, { nonce: -1 }, handleSubstrateError(chainflip)); logger.info('Withdrawal request sent!'); - logger.info('Waiting for balance change... Observing address:', withdrawAddress); + logger.debug('Waiting for balance change... Observing address:', withdrawAddress); // Wait for balance change for (let i = 0; i < balanceObserveTimeout; i++) { @@ -61,19 +61,18 @@ async function testFeeCollection( inputAsset: Asset, testContext: TestContext, ): Promise<[KeyringPair, string, string]> { - const logger = testContext.logger.child({ asset: inputAsset }); - + let logger = testContext.logger; // Setup broker accounts. Different for each asset and specific to this test. const brokerUri = `//BROKER_VAULT_FEE_COLLECTION_${inputAsset}`; const broker = createStateChainKeypair(brokerUri); const refundAddress = await newAddress('Eth', 'BTC_VAULT_SWAP_REFUND' + Math.random() * 100); - await Promise.all([setupBrokerAccount(brokerUri)]); + await Promise.all([setupBrokerAccount(logger, brokerUri)]); if (inputAsset === Assets.Btc) { - await openPrivateBtcChannel(brokerUri); + await openPrivateBtcChannel(logger, brokerUri); } logger.debug('Registering affiliate'); - const event = await registerAffiliate(brokerUri, refundAddress); + const event = await registerAffiliate(logger, brokerUri, refundAddress); const affiliateId = event.data.affiliateId as string; @@ -85,14 +84,15 @@ async function testFeeCollection( const destAsset = inputAsset === feeAsset ? Assets.Flip : feeAsset; const depositAmount = defaultAssetAmounts(inputAsset); const { destAddress, tag } = await prepareSwap( + logger, inputAsset, feeAsset, undefined, // addressType undefined, // messageMetadata 'VaultSwapFeeTest', - true, // log testContext.swapContext, ); + logger = logger.child({ tag }); // Amounts before swap const earnedBrokerFeesBefore = await getEarnedBrokerFees(broker.address); @@ -102,13 +102,12 @@ async function testFeeCollection( // Do the vault swap await performVaultSwap( + logger, inputAsset, destAsset, destAddress, - tag, undefined, // messageMetadata testContext.swapContext, - true, // log depositAmount, 0, // boostFeeBps undefined, // fillOrKillParams @@ -143,5 +142,5 @@ export async function testVaultSwapFeeCollection(testContext: TestContext) { // Test the affiliate withdrawal functionality const [broker, affiliateId, refundAddress] = await testFeeCollection(Assets.Btc, testContext); - await testWithdrawCollectedAffiliateFees(broker, affiliateId, refundAddress, testContext.logger); + await testWithdrawCollectedAffiliateFees(testContext.logger, broker, affiliateId, refundAddress); }