diff --git a/docker-compose.yml b/docker-compose.yml index 647ef57..093f017 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -165,6 +165,7 @@ services: STACKING_KEYS: 08c14a1eada0dd42b667b40f59f7c8dedb12113613448dc04980aea20b268ddb01,ce109fee08860bb16337c76647dcbc02df0c06b455dd69bcf30af74d4eedd19301,e75dcb66f84287eaf347955e94fa04337298dbd95aa0dbb985771104ef1913db01 STACKS_25_HEIGHT: *STACKS_25_HEIGHT STACKS_30_HEIGHT: *STACKS_30_HEIGHT + SERVICE_NAME: stacker depends_on: - stacks-node @@ -182,6 +183,7 @@ services: STACKS_25_HEIGHT: *STACKS_25_HEIGHT STACKS_30_HEIGHT: *STACKS_30_HEIGHT EXIT_FROM_MONITOR: *EXIT_FROM_MONITOR + SERVICE_NAME: monitor depends_on: - stacks-node entrypoint: diff --git a/stacking/common.ts b/stacking/common.ts index 5c7eacd..1c96709 100644 --- a/stacking/common.ts +++ b/stacking/common.ts @@ -9,6 +9,27 @@ import { getPublicKeyFromPrivate, publicKeyToBtcAddress } from '@stacks/encrypti import { StacksNodeApi } from '@stacks/api'; import crypto from 'crypto'; import { InfoApi, Configuration, BlocksApi, TransactionsApi } from '@stacks/blockchain-api-client'; +import pino, { Logger } from 'pino'; +import pinoPretty from 'pino-pretty'; + +const serviceName = process.env.SERVICE_NAME || 'JS'; +export let logger: Logger; +if (process.env.STACKS_LOG_JSON === '1') { + logger = pino({ + name: serviceName, + }); +} else { + logger = pino({ + name: serviceName, + transport: { + target: 'pino-pretty', + }, + // @ts-ignore + options: { + colorize: true, + }, + }); +} export const nodeUrl = `http://${process.env.STACKS_CORE_RPC_HOST}:${process.env.STACKS_CORE_RPC_PORT}`; export const network = new StacksTestnet({ url: nodeUrl }); @@ -35,7 +56,12 @@ export const accounts = process.env.STACKING_KEYS!.split(',').map((privKey, inde signerPrivKey: signerPrivKey, signerPubKey: signerPubKey, targetSlots: (index + 1) * 2, + index, client: new StackingClient(stxAddress, network), + logger: logger.child({ + account: stxAddress, + index: index, + }), }; }); @@ -48,7 +74,7 @@ export async function waitForSetup() { try { await accounts[0].client.getPoxInfo(); } catch (error) { - if (/(ECONNREFUSED|ENOTFOUND)/.test(error.cause?.message)) { + if (/(ECONNREFUSED|ENOTFOUND|SyntaxError)/.test(error.cause?.message)) { console.log(`Stacks node not ready, waiting...`); await new Promise(resolve => setTimeout(resolve, 3000)); return waitForSetup(); diff --git a/stacking/monitor-ext.sh b/stacking/monitor-ext.sh index 0cafc8a..9a8b562 100755 --- a/stacking/monitor-ext.sh +++ b/stacking/monitor-ext.sh @@ -5,5 +5,7 @@ export STACKS_CORE_RPC_PORT=80 export STACKS_30_HEIGHT=131 export STACKS_25_HEIGHT=121 export STACKING_KEYS="08c14a1eada0dd42b667b40f59f7c8dedb12113613448dc04980aea20b268ddb01,ce109fee08860bb16337c76647dcbc02df0c06b455dd69bcf30af74d4eedd19301,e75dcb66f84287eaf347955e94fa04337298dbd95aa0dbb985771104ef1913db01" +# export STACKS_LOG_JSON=1 +export SERVICE_NAME=monitor npx tsx monitor.ts \ No newline at end of file diff --git a/stacking/monitor.ts b/stacking/monitor.ts index 607f8f8..5f805e8 100644 --- a/stacking/monitor.ts +++ b/stacking/monitor.ts @@ -9,6 +9,7 @@ import { blocksApi, parseEnvInt, txApi, + logger, } from './common'; import { Transaction, ContractCallTransaction } from '@stacks/stacks-blockchain-api-types'; @@ -17,13 +18,14 @@ let lastStxHeight = 0; let lastRewardCycle = 0; let lastStxBlockTime = new Date().getTime(); let lastStxBlockDiff = 0; +let lastBlockWarnTime = 0; -console.log('Monitoring...'); +logger.info('Starting monitor script...'); const EXIT_FROM_MONITOR = process.env.EXIT_FROM_MONITOR === '1'; const monitorInterval = parseEnvInt('MONITOR_INTERVAL') ?? 2; -console.log('Exit from monitor:', EXIT_FROM_MONITOR); +logger.debug('Exit from monitor?', EXIT_FROM_MONITOR); async function getTransactions(): Promise { let res = await txApi.getTransactionsByBlock({ @@ -84,6 +86,17 @@ async function loop() { let showPrepareMsg = false; let showCycleMsg = false; let showStxBlockMsg = false; + let burnHeightDate = new Date(blockInfo.burn_block_time * 1000); + let burnHeightTimeAgo = (new Date().getTime() - burnHeightDate.getTime()) / 1000; + const loopLog = logger.child({ + height, + burnHeight: current_burnchain_block_height, + // burnHeightTime: + cycle: reward_cycle_id, + txCount: blockInfo.tx_count, + rewardCycle: reward_cycle_id, + lastBurnBlock: `${burnHeightTimeAgo.toFixed(0)}s ago`, + }); if (current_burnchain_block_height && current_burnchain_block_height !== lastBurnHeight) { if (didCrossPreparePhase(lastBurnHeight, current_burnchain_block_height)) { @@ -98,53 +111,89 @@ async function loop() { lastRewardCycle = reward_cycle_id; } + const now = new Date().getTime(); + lastStxBlockDiff = now - lastStxBlockTime; + if (height !== lastStxHeight) { showStxBlockMsg = true; lastStxHeight = height; - const now = new Date().getTime(); - lastStxBlockDiff = now - lastStxBlockTime; lastStxBlockTime = now; + lastBlockWarnTime = now; } - if (showBurnMsg) { - console.log( - `Burn block: ${current_burnchain_block_height}\tSTX block: ${height}\t${blockInfo.tx_count} TX` + // how many ms to warn about no stx blocks + const blockWarnInterval = 60 * 1000; + const lastWarnDiff = now - lastBlockWarnTime; + // if no stx block in a minute + if (lastStxBlockDiff > blockWarnInterval && lastWarnDiff > blockWarnInterval) { + // const diff = new Date().getTime() - lastStxBlockTime; + const lastSeen = new Date(lastStxBlockTime).toISOString(); + const minSinceStxBlock = (lastStxBlockDiff / (1000 * 60)).toFixed(2); + lastBlockWarnTime = now; + logger.warn( + { + lastSeen, + secSinceStxBlock: lastStxBlockDiff / 1000, + minSinceStxBlock, + }, + `No new stx block since ${minSinceStxBlock} minutes ago` ); + } + + if (showBurnMsg) { + loopLog.info('New burn block'); if (current_burnchain_block_height === EPOCH_30_START) { - console.log('Starting Nakamoto!'); + loopLog.info('Starting Nakamoto'); } } if (showPrepareMsg) { - console.log(`Prepare phase started. Next cycle is ${reward_cycle_id + 1}`); + loopLog.info( + { + nextRewardCycle: reward_cycle_id + 1, + }, + 'Prepare phase started' + ); const nextSigners = await getSignerSet(reward_cycle_id + 1); if (nextSigners) { - console.log( - `Next cycle (${info.nextCycleId}) has ${nextSigners.stacker_set.signers.length} signers` + loopLog.info( + { + nextSigners: nextSigners.stacker_set.signers.length, + }, + `Next cycle (${reward_cycle_id + 1}) has ${ + nextSigners.stacker_set.signers.length + } signers` ); } } - if (!showBurnMsg && showStxBlockMsg) { - console.log( - `Nakamoto block: ${height}\t${blockInfo.tx_count} TX\t(${(lastStxBlockDiff / 1000).toFixed( - 2 - )} seconds)` - ); + if (!showBurnMsg && showStxBlockMsg && blockInfo.burn_block_height >= EPOCH_30_START) { + loopLog.info({ lastStxBlockDiff: lastStxBlockDiff / 1000 }, 'Nakamoto block'); } if (showStxBlockMsg && info.txs.length > 0) { - info.txs.forEach(({ contract_call, sender_address, tx_status }) => { - console.log(`${sender_address}:\t${contract_call.function_name}\t${tx_status}`); + info.txs.forEach(({ contract_call, sender_address, tx_status, ...tx }) => { + loopLog.info( + { + sender_address, + contract_call: contract_call.function_name, + tx_status, + tx_result: tx.tx_result.repr, + }, + 'New transaction confirmed' + ); }); } if (showCycleMsg) { const currentSigners = await getSignerSet(reward_cycle_id); const signerCount = currentSigners?.stacker_set.signers.length ?? 0; - console.log(`New cycle started (${reward_cycle_id}) with ${signerCount} signers`); + loopLog.info( + { signerCount }, + `New cycle started (${reward_cycle_id}) with ${signerCount} signers` + ); } if (reward_cycle_id >= EPOCH_30_START && !poxInfo.reward_slots) { - console.error('FATAL: no signers while going in to Epoch 3.0'); + logger.error('FATAL: no signers while going in to Epoch 3.0'); exit(); } } catch (error) { @@ -154,16 +203,13 @@ async function loop() { } else { console.error(error); } - console.error(message); - // if (!message.toLowerCase().includes('fetch failed')) { - // throw error; - // } + logger.error(message); } } function exit() { if (EXIT_FROM_MONITOR) { - console.log('Exiting...'); + logger.info('Exiting...'); process.exit(1); } } diff --git a/stacking/package.json b/stacking/package.json index 49c0693..3e14e19 100644 --- a/stacking/package.json +++ b/stacking/package.json @@ -9,13 +9,15 @@ "license": "ISC", "dependencies": { "@stacks/api": "6.11.4-pr.472091f.0", + "@stacks/blockchain-api-client": "7.8.2", + "@stacks/common": "6.11.4-pr.36558cf.0", "@stacks/encryption": "6.11.4-pr.36558cf.0", "@stacks/network": "6.11.4-pr.36558cf.0", "@stacks/stacking": "6.11.4-pr.36558cf.0", + "@stacks/stacks-blockchain-api-types": "7.8.2", "@stacks/transactions": "6.11.4-pr.36558cf.0", - "@stacks/common": "6.11.4-pr.36558cf.0", - "@stacks/blockchain-api-client": "7.8.2", - "@stacks/stacks-blockchain-api-types": "7.8.2" + "pino": "^8.19.0", + "pino-pretty": "^10.3.1" }, "devDependencies": { "@stacks/prettier-config": "^0.0.10", diff --git a/stacking/stacking.ts b/stacking/stacking.ts index 56e5136..8b5735e 100644 --- a/stacking/stacking.ts +++ b/stacking/stacking.ts @@ -7,7 +7,7 @@ import { } from '@stacks/transactions'; import { getPublicKeyFromPrivate, publicKeyToBtcAddress } from '@stacks/encryption'; import crypto from 'crypto'; -import { Account, accounts, network, maxAmount, parseEnvInt, waitForSetup } from './common'; +import { Account, accounts, network, maxAmount, parseEnvInt, waitForSetup, logger } from './common'; const randInt = () => crypto.randomInt(0, 0xffffffffffff); const stackingInterval = parseEnvInt('STACKING_INTERVAL') ?? 2; @@ -18,11 +18,21 @@ async function run() { await waitForSetup(); const poxInfo = await accounts[0].client.getPoxInfo(); if (!poxInfo.contract_id.endsWith('.pox-4')) { - console.log(`Pox contract is not .pox-4, skipping stacking (contract=${poxInfo.contract_id})`); + // console.log(`Pox contract is not .pox-4, skipping stacking (contract=${poxInfo.contract_id})`); + logger.info( + { + poxContract: poxInfo.contract_id, + }, + `Pox contract is not .pox-4, skipping stacking (contract=${poxInfo.contract_id})` + ); return; } const nextCycleStartHeight = poxInfo.next_cycle.prepare_phase_start_block_height; + const runLog = logger.child({ + burnHeight: poxInfo.current_burnchain_block_height, + }); + const accountInfos = await Promise.all( accounts.map(async a => { const info = await a.client.getAccountStatus(); @@ -39,26 +49,36 @@ async function run() { const minStx = Math.floor(poxInfo.next_cycle.min_threshold_ustx * 1.5); const nextCycleStx = poxInfo.next_cycle.stacked_ustx; if (nextCycleStx < minStx) { + runLog.info(`Next cycle has less than min threshold, force extending`); forceExtend = true; } await Promise.all( accountInfos.map(async account => { if (account.lockedAmount === 0n) { - console.log(`Account ${account.stxAddress} is unlocked, stack-stx required`); + runLog.info(`Account ${account.index} is unlocked, stack-stx required`); await stackStx(poxInfo, account); txSubmitted = true; return; } if (forceExtend || account.unlockHeight <= nextCycleStartHeight - 5) { - console.log( - `Account ${account.stxAddress} unlocks before next cycle ${account.unlockHeight} vs ${nextCycleStartHeight}, stack-extend required` + runLog.info( + { + burnHeight: poxInfo.current_burnchain_block_height, + }, + `Account ${account.index} unlocks before next cycle ${account.unlockHeight} vs ${nextCycleStartHeight}, stack-extend required` ); await stackExtend(poxInfo, account); txSubmitted = true; return; } - console.log(`Account ${account.stxAddress} is locked for next cycle, skipping stacking`); + runLog.info( + { + burnHeight: poxInfo.current_burnchain_block_height, + }, + `Account ${account.index} is locked for next cycle, skipping stacking` + ); + // console.log(`Account ${account.stxAddress} is locked for next cycle, skipping stacking`); }) ); @@ -67,11 +87,7 @@ async function run() { } } -/** - * @param {import('@stacks/stacking').PoxInfo} poxInfo - * @param {typeof accounts[0]} account - */ -async function stackStx(poxInfo: PoxInfo, account) { +async function stackStx(poxInfo: PoxInfo, account: Account) { // Bump min threshold by 50% to avoid getting stuck if threshold increases const minStx = Math.floor(poxInfo.next_cycle.min_threshold_ustx * 1.5); const amountToStx = Math.round(minStx * account.targetSlots); @@ -98,13 +114,20 @@ async function stackStx(poxInfo: PoxInfo, account) { authId, maxAmount, }; - console.log('Stack-stx with args:', { - addr: account.stxAddress, - ...stackingArgs, - ...sigArgs, - }); + account.logger.debug( + { + ...stackingArgs, + ...sigArgs, + }, + `Stack-stx with args:` + ); const stackResult = await account.client.stack(stackingArgs); - console.log('Stack-stx tx result', stackResult); + account.logger.info( + { + ...stackResult, + }, + `Stack-stx tx result` + ); } async function stackExtend(poxInfo: PoxInfo, account: Account) { @@ -129,13 +152,24 @@ async function stackExtend(poxInfo: PoxInfo, account: Account) { authId, maxAmount, }; - console.log('Stack-extend with args:', { - addr: account.stxAddress, - ...stackingArgs, - ...sigArgs, - }); + account.logger.debug( + { + stxAddress: account.stxAddress, + account: account.index, + ...stackingArgs, + ...sigArgs, + }, + `Stack-extend with args:` + ); const stackResult = await account.client.stackExtend(stackingArgs); - console.log('Stack-extend tx result', stackResult); + account.logger.info( + { + stxAddress: account.stxAddress, + account: account.index, + ...stackResult, + }, + `Stack-extend tx result` + ); } async function loop() {