diff --git a/src/commands/dumpDb.ts b/src/commands/dumpDb.ts index 5f67f7c..553ba1a 100644 --- a/src/commands/dumpDb.ts +++ b/src/commands/dumpDb.ts @@ -7,7 +7,7 @@ import { getLogger } from "../utils"; * @param options A dict, but essentially just the chainId */ export async function dumpDb(options: DumpDbOptions) { - const log = getLogger("commands:dumpDb"); + const log = getLogger({ name: "commands:dumpDb" }); const { chainId, databasePath } = options; Registry.dump(DBService.getInstance(databasePath), chainId.toString()) diff --git a/src/commands/run.ts b/src/commands/run.ts index 0ad7745..873573f 100644 --- a/src/commands/run.ts +++ b/src/commands/run.ts @@ -7,7 +7,7 @@ import { DBService, ApiService, ChainContext } from "../services"; * @param options Specified by the CLI / environment for running the watch-tower */ export async function run(options: RunOptions) { - const log = getLogger("commands:run"); + const log = getLogger({ name: "commands:run" }); const { oneShot, disableApi, apiPort, databasePath, networks } = options; // Open the database @@ -66,7 +66,7 @@ export async function run(options: RunOptions) { * @param exitCode Exit code to return to the shell */ async function stop(exitCode?: number) { - const log = getLogger("commands:stop"); + const log = getLogger({ name: "commands:stop" }); const stopServices = [ ApiService.getInstance().stop(), DBService.getInstance().close(), diff --git a/src/domain/events/index.ts b/src/domain/events/index.ts index 6220577..dc1a754 100644 --- a/src/domain/events/index.ts +++ b/src/domain/events/index.ts @@ -17,79 +17,94 @@ import { Proof, Registry, } from "../../types"; -import { ConditionalOrder, ConditionalOrderParams } from "@cowprotocol/cow-sdk"; +import { + ConditionalOrder, + ConditionalOrderParams, + SupportedChainId, +} from "@cowprotocol/cow-sdk"; import { ChainContext } from "../../services/chain"; const composableCow = ComposableCoW__factory.createInterface(); /** - * Listens to these events on the `ComposableCoW` contract: + * Process a new order event for `ComposableCoW` contract: * - `ConditionalOrderCreated` * - `MerkleRootSet` + * * @param context chain context * @param event transaction event */ -export async function addContract( +export async function processNewOrderEvent( context: ChainContext, event: ConditionalOrderCreatedEvent ) { const { chainId } = context; - await metrics.measureTime({ - action: () => _addContract(context, event), - labelValues: [chainId.toString()], - durationMetric: metrics.addContractsRunDurationSeconds, - totalRunsMetric: metrics.addContractRunsTotal, - errorHandler: handleExecutionError, - errorMetric: metrics.addContractsErrorsTotal, - }); -} -async function _addContract( - context: ChainContext, - event: ConditionalOrderCreatedEvent -) { - const log = getLogger("addContract:_addContract"); - const { registry } = context; - const { transactionHash: tx, blockNumber } = event; + const action = async () => { + const { registry, chainId } = context; + const { transactionHash: tx, blockNumber } = event; - // Process the logs - let hasErrors = false; - let numContractsAdded = 0; + const log = getLogger({ + name: "processNewOrderEvent", + chainId, + blockNumber: event.blockNumber, + }); - const { error, added } = await registerNewOrder(event, registry); + // Process the logs + let hasErrors = false; + let numContractsAdded = 0; - if (added) { - metrics.ownersTotal.labels(context.chainId.toString()).inc(); - numContractsAdded++; - } else { - log.error( - `Failed to register Smart Order from tx ${tx} on block ${blockNumber}. Error: ${error}` - ); - } + const { error, added } = await decodeAndAddOrder(event, registry, chainId); + + if (added) { + metrics.ownersTotal.labels(context.chainId.toString()).inc(); + numContractsAdded++; + } else { + log.error( + `Failed to register Smart Order from tx ${tx} on block ${blockNumber}. Error: ${error}` + ); + } - hasErrors ||= error; + hasErrors ||= error; - if (numContractsAdded > 0) { - log.debug(`Added ${numContractsAdded} contracts`); + if (numContractsAdded > 0) { + log.debug(`Added ${numContractsAdded} conditional orders`); - // Write the registry to disk. Don't catch errors, let them bubble up - await registry.write(); + // Write the registry to disk. Don't catch errors, let them bubble up + await registry.write(); - // Throw execution error if there was at least one error - if (hasErrors) { - throw Error("Error adding conditional order. Event: " + event); + // Throw execution error if there was at least one error + if (hasErrors) { + throw Error("Error adding conditional order. Event: " + event); + } + } else { + log.info( + `No conditional order added for tx ${tx} on block ${blockNumber}` + ); } - } else { - log.info(`No contracts added for tx ${tx} on block ${blockNumber}`); - } + }; + + await metrics.measureTime({ + action, + labelValues: [chainId.toString()], + durationMetric: metrics.addContractsRunDurationSeconds, + totalRunsMetric: metrics.addContractRunsTotal, + errorHandler: handleExecutionError, + errorMetric: metrics.addContractsErrorsTotal, + }); } -async function registerNewOrder( +async function decodeAndAddOrder( event: ConditionalOrderCreatedEvent | MerkleRootSetEvent, - registry: Registry + registry: Registry, + chainId: SupportedChainId ): Promise<{ error: boolean; added: boolean }> { - const log = getLogger("addContract:registerNewOrder"); + const log = getLogger({ + name: "decodeAndAddOrder", + chainId, + blockNumber: event.blockNumber, + }); const { transactionHash: tx } = event; const { network } = registry; let added = false; @@ -108,13 +123,15 @@ async function registerNewOrder( ) as [string, IConditionalOrder.ConditionalOrderParamsStruct]; // Attempt to add the conditional order to the registry - add( + addOrder( eventLog.transactionHash, owner, toConditionalOrderParams(params), null, eventLog.address, - registry + registry, + chainId, + event.blockNumber ); added = true; metrics.singleOrdersTotal.labels(network).inc(); @@ -149,13 +166,15 @@ async function registerNewOrder( order as BytesLike ); // Attempt to add the conditional order to the registry - add( + addOrder( event.transactionHash, owner, toConditionalOrderParams(decodedOrder[1]), { merkleRoot: root, path: decodedOrder[0] }, eventLog.address, - registry + registry, + chainId, + event.blockNumber ); added = true; metrics.merkleRootTotal.labels(network).inc(); @@ -174,7 +193,7 @@ async function registerNewOrder( } /** - * Attempt to add an owner's conditional order to the registry + * Attempt to add a conditional order to the registry * * @param tx transaction that created the conditional order * @param owner to add the conditional order to @@ -183,25 +202,30 @@ async function registerNewOrder( * @param composableCow address of the contract that emitted the event * @param registry of all conditional orders */ -function add( +function addOrder( tx: string, owner: Owner, params: ConditionalOrderParams, proof: Proof | null, composableCow: string, - registry: Registry + registry: Registry, + chainId: SupportedChainId, + blockNumber: number ) { - const log = getLogger("addContract:add"); + const log = getLogger({ name: "addOrder", chainId, blockNumber }); const { handler, salt, staticInput } = params; const { network, ownerOrders } = registry; const conditionalOrderId = ConditionalOrder.leafToId(params); if (ownerOrders.has(owner)) { const conditionalOrders = ownerOrders.get(owner); - log.info( - `Adding conditional order to already existing owner contract ${owner}`, - { conditionalOrderId, tx, handler, salt, staticInput } - ); + log.info(`Adding conditional order to already existing owner ${owner}`, { + conditionalOrderId, + tx, + handler, + salt, + staticInput, + }); let exists = false; // Iterate over the conditionalOrders to make sure that the params are not already in the registry for (const conditionalOrder of conditionalOrders?.values() ?? []) { @@ -229,7 +253,7 @@ function add( metrics.activeOrdersTotal.labels(network).inc(); } } else { - log.info(`Adding conditional order to new owner contract ${owner}:`, { + log.info(`Adding conditional order to new owner ${owner}:`, { conditionalOrderId, tx, handler, diff --git a/src/domain/polling/index.ts b/src/domain/polling/index.ts index 1453af3..36ea339 100644 --- a/src/domain/polling/index.ts +++ b/src/domain/polling/index.ts @@ -107,7 +107,7 @@ export async function checkForAndPlaceOrder( blockTimestampOverride?: number ) { const { chainId, registry, filterPolicy } = context; - const { ownerOrders, numOrders } = registry; + const { ownerOrders, numOrders, numOwners } = registry; const blockNumber = blockNumberOverride || block.number; const blockTimestamp = blockTimestampOverride || block.timestamp; @@ -117,33 +117,41 @@ export async function checkForAndPlaceOrder( let orderCounter = 0; let updatedCount = 0; - const log = getLogger( - "checkForAndPlaceOrder:checkForAndPlaceOrder", - chainId.toString(), - blockNumber.toString() - ); - log.debug(`Total number of orders: ${numOrders}`); + const loggerParams = { + name: "checkForAndPlaceOrder", + chainId, + blockNumber, + }; + const log = getLogger(loggerParams); + log.debug(`The registry has ${numOwners} owners and ${numOrders} orders`); for (const [owner, conditionalOrders] of ownerOrders.entries()) { ownerCounter++; - const log = getLogger( - "checkForAndPlaceOrder:checkForAndPlaceOrder", - chainId.toString(), - blockNumber.toString(), - ownerCounter.toString() - ); + const log = getLogger({ + ...loggerParams, + ownerNumber: ownerCounter, + }); let ordersPendingDelete = []; - log.debug(`Process owner ${owner} (${conditionalOrders.size} orders)`); + log.debug( + `Process owner ${ownerCounter}/${numOwners}. Owner=${owner}. Orders=${conditionalOrders.size}` + ); for (const conditionalOrder of conditionalOrders) { orderCounter++; + const log = getLogger({ + ...loggerParams, + blockNumber, + ownerNumber: ownerCounter, + orderNumber: orderCounter, + }); + // Check if we reached the chunk size if (updatedCount % CHUNK_SIZE === 1 && updatedCount > 1) { // Delete orders pending delete, if any - _deleteOrders(ordersPendingDelete, conditionalOrders, log, chainId); + deleteOrders(ordersPendingDelete, conditionalOrders, log, chainId); // Reset tracker ordersPendingDelete = []; @@ -153,9 +161,7 @@ export async function checkForAndPlaceOrder( await registry.write(); } - const ownerRef = `${ownerCounter}.${orderCounter}`; - const orderRef = `${chainId}:${blockNumber}:${ownerRef}`; - const logOrderDetails = `Processing order ${conditionalOrder.id} from TX ${conditionalOrder.tx} with params:`; + const logOrderDetails = `Processing order ${orderCounter}/${numOrders} with ID ${conditionalOrder.id} from TX ${conditionalOrder.tx} with params:`; const { result: lastHint } = conditionalOrder.pollResult || {}; @@ -212,13 +218,14 @@ export async function checkForAndPlaceOrder( // Proceed with the normal check log.info(`${logOrderDetails}`, conditionalOrder.params); - const pollResult = await _processConditionalOrder( + const pollResult = await processConditionalOrder( owner, conditionalOrder, blockTimestamp, blockNumber, context, - orderRef + ownerCounter, + orderCounter ); // Don't try again the same order, in case that's the poll result @@ -246,7 +253,7 @@ export async function checkForAndPlaceOrder( (isError && pollResult.reason ? `. Reason: ${pollResult.reason}` : ""); log[unexpectedError ? "error" : "info"]( - `Check conditional order result for ${ + `Check conditional order result for order ${ conditionalOrder.id }: ${getEmojiByPollResult(pollResult?.result)} ${resultDescription}` ); @@ -261,7 +268,7 @@ export async function checkForAndPlaceOrder( } // Delete orders we don't want to keep watching - _deleteOrders(ordersPendingDelete, conditionalOrders, log, chainId); + deleteOrders(ordersPendingDelete, conditionalOrders, log, chainId); } // It may be handy in other versions of the watch tower implemented in other languages @@ -278,7 +285,7 @@ export async function checkForAndPlaceOrder( await registry.write(); log.debug( - `Total orders after processing all conditional orders: ${registry.numOrders}` + `After processing orders. Owners=${registry.numOwners}, Orders=${registry.numOrders}` ); // Throw execution error if there was at least one error @@ -287,14 +294,18 @@ export async function checkForAndPlaceOrder( } } -function _deleteOrders( +function deleteOrders( ordersPendingDelete: ConditionalOrder[], conditionalOrders: Set, log: LoggerWithMethods, chainId: SupportedChainId ) { ordersPendingDelete.length && - log.debug(`${ordersPendingDelete.length} to delete`); + log.debug( + `Delete ${ordersPendingDelete.length} orders: ${ordersPendingDelete.join( + ", " + )}` + ); for (const conditionalOrder of ordersPendingDelete) { const deleted = conditionalOrders.delete(conditionalOrder); @@ -307,21 +318,25 @@ function _deleteOrders( } } -async function _processConditionalOrder( +async function processConditionalOrder( owner: string, conditionalOrder: ConditionalOrder, blockTimestamp: number, blockNumber: number, context: ChainContext, - orderRef: string + ownerNumber: number, + orderNumber: number ): Promise { const { provider, orderBookApi, dryRun, chainId } = context; const { handler } = conditionalOrder.params; - const log = getLogger( - "checkForAndPlaceOrder:_processConditionalOrder", - orderRef - ); + const log = getLogger({ + name: "processConditionalOrder", + chainId, + blockNumber, + ownerNumber, + orderNumber, + }); const metricLabels = [ chainId.toString(), handler, @@ -348,11 +363,15 @@ async function _processConditionalOrder( provider, orderBookApi, }; + let pollResult = await pollConditionalOrder( conditionalOrder.id, pollParams, conditionalOrder.params, - orderRef + chainId, + blockNumber, + ownerNumber, + orderNumber ); if (!pollResult) { @@ -361,13 +380,15 @@ async function _processConditionalOrder( // TODO: Decide in the future what to do. Probably, move the error handling to the SDK and kill the poll Legacy pollResult = await metrics.measureTime({ action: () => - _pollLegacy( + pollLegacy( context, owner, conditionalOrder, proof, offchainInput, - orderRef + blockNumber, + ownerNumber, + orderNumber ), labelValues: metricLabels, durationMetric: metrics.pollingOnChainDurationSeconds, @@ -407,20 +428,23 @@ async function _processConditionalOrder( } // calculate the orderUid - const orderUid = _getOrderUid(chainId, orderToSubmit, owner); + const orderUid = getOrderUid(chainId, orderToSubmit, owner); // Place order, if the orderUid has not been submitted or filled if (!conditionalOrder.orders.has(orderUid)) { // Place order - const placeOrderResult = await _placeOrder({ + const placeOrderResult = await postDiscreteOrder({ conditionalOrder, orderUid, order: { ...orderToSubmit, from: owner, signature }, orderBookApi, blockTimestamp, - orderRef, dryRun, metricLabels, + chainId, + blockNumber, + ownerNumber, + orderNumber, }); // In case of error, return early @@ -457,7 +481,7 @@ async function _processConditionalOrder( } } -function _getOrderUid( +function getOrderUid( chainId: SupportedChainId, orderToSubmit: Order, owner: string @@ -501,27 +525,40 @@ export const _printUnfilledOrders = (orders: Map) => { * @param order to be placed on the cow protocol api * @param apiUrl rest api url */ -async function _placeOrder(params: { +async function postDiscreteOrder(params: { conditionalOrder: ConditionalOrder; orderUid: string; order: any; orderBookApi: OrderBookApi; - orderRef: string; blockTimestamp: number; dryRun: boolean; metricLabels: string[]; + chainId: SupportedChainId; + blockNumber: number; + ownerNumber: number; + orderNumber: number; }): Promise | PollResultErrors> { const { conditionalOrder, orderUid, order, orderBookApi, - orderRef, blockTimestamp, dryRun, metricLabels, + chainId, + blockNumber, + ownerNumber, + orderNumber, } = params; - const log = getLogger("checkForAndPlaceOrder:_placeOrder", orderRef); + const log = getLogger({ + name: "postDiscreteOrder", + chainId, + blockNumber, + ownerNumber, + orderNumber, + }); + try { const postOrder: OrderCreation = { kind: order.kind, @@ -557,7 +594,7 @@ async function _placeOrder(params: { const { status } = error.response; const { body } = error; - const handleErrorResult = _handleOrderBookError( + const handleErrorResult = handleOrderBookError( status, body, error, @@ -596,7 +633,7 @@ async function _placeOrder(params: { return { result: PollResultCode.SUCCESS }; } -function _handleOrderBookError( +function handleOrderBookError( status: any, body: any, error: any, @@ -687,16 +724,24 @@ function _handleOrderBookError( }; } -async function _pollLegacy( +async function pollLegacy( context: ChainContext, owner: string, conditionalOrder: ConditionalOrder, proof: string[], offchainInput: string, - orderRef: string + blockNumber: number, + ownerNumber: number, + orderNumber: number ): Promise { const { contract, multicall, chainId } = context; - const log = getLogger("checkForAndPlaceOrder:_pollLegacy", orderRef); + const log = getLogger({ + name: "pollLegacy", + chainId, + blockNumber, + ownerNumber, + orderNumber, + }); const { composableCow: target } = conditionalOrder; const { handler } = conditionalOrder.params; // as we going to use multicall, with `aggregate3Value`, there is no need to do any simulation as the @@ -750,12 +795,14 @@ async function _pollLegacy( // order types created that are _not_ adhering to the interface (and are therefore invalid). return handleOnChainCustomError({ owner, - orderRef, chainId, target, callData, revertData: returnData, metricLabels, + blockNumber, + ownerNumber, + orderNumber, }); } catch (error: any) { // We can only get here from some provider / ethers failure. As the contract hasn't had it's say diff --git a/src/domain/polling/poll.ts b/src/domain/polling/poll.ts index be1f139..6f86568 100644 --- a/src/domain/polling/poll.ts +++ b/src/domain/polling/poll.ts @@ -4,6 +4,7 @@ import { DEFAULT_CONDITIONAL_ORDER_REGISTRY, PollParams, PollResult, + SupportedChainId, } from "@cowprotocol/cow-sdk"; import { getLogger } from "../../utils/logging"; @@ -18,9 +19,19 @@ export async function pollConditionalOrder( conditionalOrderId: string, pollParams: PollParams, conditionalOrderParams: ConditionalOrderParams, - orderRef: string + chainId: SupportedChainId, + blockNumber: number, + ownerNumber: number, + orderNumber: number ): Promise { - const log = getLogger("pollConditionalOrder:pollConditionalOrder", orderRef); + const log = getLogger({ + name: "pollConditionalOrder", + chainId, + blockNumber, + ownerNumber, + orderNumber, + }); + const order = ordersFactory.fromParams(conditionalOrderParams); if (!order) { diff --git a/src/services/api.ts b/src/services/api.ts index 1d5b47e..cbc13f4 100644 --- a/src/services/api.ts +++ b/src/services/api.ts @@ -50,7 +50,7 @@ export class ApiService { async start(): Promise { return await new Promise((resolve, reject) => { try { - const log = getLogger("api:start"); + const log = getLogger({ name: "api:start" }); if (this.server?.listening) { throw new Error("Server is already running"); } @@ -74,7 +74,7 @@ export class ApiService { throw new Error("Server is not running"); } - const log = getLogger("api:stop"); + const log = getLogger({ name: "api:stop" }); log.info("Stopping Rest API server..."); this.server.once("close", resolve); diff --git a/src/services/chain.ts b/src/services/chain.ts index 7bdbdec..ace123e 100644 --- a/src/services/chain.ts +++ b/src/services/chain.ts @@ -5,7 +5,7 @@ import { } from "@cowprotocol/cow-sdk"; import { ethers, providers } from "ethers"; import { DBService } from "."; -import { addContract } from "../domain/events"; +import { processNewOrderEvent } from "../domain/events"; import { checkForAndPlaceOrder } from "../domain/polling"; import { policy } from "../domain/polling/filtering"; import { @@ -171,7 +171,7 @@ export class ChainContext { */ public async warmUp(oneShot?: boolean) { const { provider, chainId, processEveryNumBlocks } = this; - const log = getLogger("chainContext:warmUp", chainId.toString()); + const log = getLogger({ name: "warmUp", chainId }); let { lastProcessedBlock } = this.registry; const { pageSize } = this; @@ -290,7 +290,7 @@ export class ChainContext { } while (this.sync === ChainSync.SYNCING); log.info( - `💚 ${ + `☀️ ${ oneShot ? "Chain watcher is in sync" : "Chain watcher is warmed up" }` ); @@ -302,7 +302,7 @@ export class ChainContext { } // Otherwise, run the block watcher - return await this.runBlockWatcher(currentBlock); + return await this.subscribeToNewBlocks(currentBlock); } /** @@ -310,16 +310,22 @@ export class ChainContext { * 1. Check if there are any `ConditionalOrderCreated` events, and index these. * 2. Check if any orders want to create discrete orders. */ - private async runBlockWatcher(lastProcessedBlock: providers.Block) { + private async subscribeToNewBlocks(lastProcessedBlock: providers.Block) { const { provider, registry, chainId, watchdogTimeout } = this; - const log = getLogger("chainContext:runBlockWatcher", chainId.toString()); + const loggerName = "subscribeToNewBlocks"; + let log = getLogger({ name: loggerName, chainId }); // Watch for new blocks log.info(`👀 Start block watcher`); log.debug(`Watchdog timeout: ${watchdogTimeout} seconds`); let lastBlockReceived = lastProcessedBlock; provider.on("block", async (blockNumber: number) => { try { - log.debug(`New block ${blockNumber}`); + log = getLogger({ + name: loggerName, + chainId, + blockNumber, + }); + log.debug("New block received"); const block = await provider.getBlock(blockNumber); @@ -436,7 +442,7 @@ export class ChainContext { * @param blockNumberOverride to override the block number when polling the SDK * @param blockTimestampOverride to override the block timestamp when polling the SDK */ -async function processBlock( +async function processBlockEvent( context: ChainContext, block: providers.Block, events: ConditionalOrderCreatedEvent[], @@ -448,11 +454,11 @@ async function processBlock( .labels(context.chainId.toString()) .startTimer(); - const log = getLogger( - "chainContext:processBlock", - chainId.toString(), - block.number.toString() - ); + const log = getLogger({ + name: "processBlockEvent", + chainId, + blockNumber: block.number, + }); // Transaction watcher for adding new contracts let hasErrors = false; @@ -461,15 +467,22 @@ async function processBlock( if (receipt) { // run action - log.debug(`Running "addContract" action for TX ${event.transactionHash}`); - const result = await addContract(context, event) + log.debug(`Process new order event of TX ${event.transactionHash}`); + const result = await processNewOrderEvent(context, event) .then(() => true) .catch((e) => { hasErrors = true; - log.error(`Error running "addContract" action for TX:`, e); + log.error( + `Error processing new order event of TX ${event.transactionHash}:`, + e + ); return false; }); - log.info(`Result of "addContract": ${_formatResult(result)}`); + log.info( + `Result of processing new order event of TX ${ + event.transactionHash + }: ${_formatResult(result)}` + ); metrics.eventsProcessedTotal.labels(chainId.toString()).inc(); } } @@ -518,7 +531,7 @@ async function persistLastProcessedBlock(params: { // Save the registry await context.registry.write(); - log.debug(`Block ${blockNumber} has been processed`); + log.debug(`Block has been processed`); // Set the block height metric metrics.blockHeight.labels(context.chainId.toString()).set(blockNumber); @@ -542,7 +555,7 @@ async function processBlockAndPersist(params: { const _block = block || (await provider.getBlock(blockNumber)); try { - await processBlock( + await processBlockEvent( context, _block, events, @@ -598,7 +611,8 @@ function _formatResult(result: boolean) { } function getProvider(rpcUrl: string): providers.Provider { - const log = getLogger("getProvider", rpcUrl); + const log = getLogger({ name: "getProvider", args: [rpcUrl] }); + // if the rpcUrl is a websocket url, use the WebSocketProvider if (rpcUrl.startsWith("ws")) { log.debug("Instantiating WS"); diff --git a/src/services/storage.ts b/src/services/storage.ts index 7c3d145..153379c 100644 --- a/src/services/storage.ts +++ b/src/services/storage.ts @@ -28,13 +28,13 @@ export class DBService { } public async open() { - const log = getLogger("dbService:open"); + const log = getLogger({ name: "dbService:open" }); log.info("Opening database..."); await this.db.open(); } public async close() { - const log = getLogger("dbService:close"); + const log = getLogger({ name: "dbService:close" }); log.info("Closing database..."); await this.db.close(); } diff --git a/src/types/model.ts b/src/types/model.ts index 42ab571..f5216ec 100644 --- a/src/types/model.ts +++ b/src/types/model.ts @@ -110,7 +110,7 @@ export class Registry { network: string; lastNotifiedError: Date | null; lastProcessedBlock: RegistryBlock | null; - readonly logger = getLogger("Registry"); + readonly logger = getLogger({ name: "Registry" }); /** * Instantiates a registry. * @param ownerOrders What map to populate the registry with @@ -200,6 +200,10 @@ export class Registry { return getOrdersCountFromOrdersPerOwner(this.ownerOrders); } + get numOwners(): number { + return this.ownerOrders.size; + } + /** * Write the registry to storage. */ @@ -250,10 +254,9 @@ export class Registry { await batch.write(); this.logger.debug( - `write:${this.version}:${this.network}:${ - this.lastProcessedBlock?.number - }:${this.lastNotifiedError || ""}`, - "batch written 📝" + `${this.network}@${this.lastProcessedBlock?.number}:v${this.version}${ + this.lastNotifiedError ? ":lastError_" + this.lastNotifiedError : "" + } DB persisted` ); } @@ -293,7 +296,7 @@ async function loadOwnerOrders( storage: DBService, network: string ): Promise { - const loadOwnerOrdersLogger = getLogger("loadOwnerOrders"); + const loadOwnerOrdersLogger = getLogger({ name: "loadOwnerOrders" }); // Get the owner orders const db = storage.getDB(); const str = await db.get( diff --git a/src/utils/context.ts b/src/utils/context.ts index a094229..939f19a 100644 --- a/src/utils/context.ts +++ b/src/utils/context.ts @@ -59,7 +59,7 @@ function _getSlack(options: ContextOptions): Slack | undefined { } export async function handleExecutionError(e: any) { - const log = getLogger("context:handleExecutionError"); + const log = getLogger({ name: "context:handleExecutionError" }); try { const errorMessage = e?.message || "Unknown error"; const notified = sendSlack( @@ -80,7 +80,7 @@ export async function handleExecutionError(e: any) { } export function sendSlack(message: string): boolean { - const log = getLogger("context:sendSlack"); + const log = getLogger({ name: "context:sendSlack" }); if (!executionContext) { log.warn("Slack not initialized, ignoring message", message); return false; diff --git a/src/utils/contracts.ts b/src/utils/contracts.ts index 0bc6a18..80e9f4e 100644 --- a/src/utils/contracts.ts +++ b/src/utils/contracts.ts @@ -198,33 +198,44 @@ export function parseCustomError(revertData: string): ParsedCustomError { */ export function handleOnChainCustomError(params: { owner: string; - orderRef: string; chainId: SupportedChainId; target: string; callData: string; revertData: string; metricLabels: string[]; + blockNumber: number; + ownerNumber: number; + orderNumber: number; }): PollResultErrors { const { owner, - orderRef, chainId, target, callData, revertData, metricLabels, + blockNumber, + ownerNumber, + orderNumber, } = params; + const loggerParams = { + name: "handleOnChainCustomError", + chainId, + blockNumber, + ownerNumber, + orderNumber, + }; + try { // The below will throw if: // - the error is not a custom error (ie. the selector is not in the map) // - the error is a custom error, but the parameters are not as expected const parsedCustomError = parseCustomError(revertData); const { selector } = parsedCustomError; - const log = getLogger( - "contracts:handleOnChainCustomError", - orderRef, - selector - ); + const log = getLogger({ + ...loggerParams, + args: [selector], + }); const msgWithSelector = (message: string): string => `${selector}: ${message}`; const dropOrder = (reason: string): PollResultErrors => { @@ -293,7 +304,8 @@ export function handleOnChainCustomError(params: { } catch (err: any) { // Any errors thrown here can _ONLY_ come from non-compliant interfaces (ie. bad revert ABI encoding). // We log the error, and return a DONT_TRY_AGAIN result. - const log = getLogger("contracts:handleOnChainCustomError", orderRef); + const log = getLogger(loggerParams); + log.debug( `Non-compliant interface error thrown${ err.message ? `: ${err.message}` : "" diff --git a/src/utils/logging.ts b/src/utils/logging.ts index b8fdd69..d761cb9 100644 --- a/src/utils/logging.ts +++ b/src/utils/logging.ts @@ -6,6 +6,7 @@ import { import rootLogger from "loglevel"; import prefix from "loglevel-plugin-prefix"; import chalk, { Chalk } from "chalk"; +import { SupportedChainId } from "@cowprotocol/cow-sdk"; const DEFAULT_LOG_LEVEL = "INFO"; const LEVELS = ["TRACE", "DEBUG", "INFO", "WARN", "ERROR", "SILENT"]; @@ -54,36 +55,60 @@ export interface LoggerWithMethods { error: (...msg: any[]) => void; } -export function getLogger( - loggerName: string, - ...args: string[] -): LoggerWithMethods { +interface GetLoggerParams { + name: string; + chainId?: SupportedChainId; + blockNumber?: number; + ownerNumber?: number; + orderNumber?: number; + args?: string[]; +} + +/** + * Get the log prefix for a given logger. This is used to add context to the log messages. + */ +function getLogPrefix({ + chainId, + blockNumber, + ownerNumber, + orderNumber, + args = [], +}: GetLoggerParams) { + const chainString = chainId ? `${chainId}` : ""; + const blockString = blockNumber ? `@${blockNumber}` : ""; + const ownerString = ownerNumber ? `#${ownerNumber}` : ""; + const orderString = orderNumber ? `.${orderNumber}` : ""; + const argsString = args.length > 0 ? " " + args.join(":") : ""; + + return chainString + blockString + ownerString + orderString + argsString; +} + +export function getLogger(params: GetLoggerParams): LoggerWithMethods { if (!logLevelOverrides) { throw new Error("Logging hasn't been initialized"); } - const logger = getLoggerLogLevel(loggerName); + const { name } = params; + const logger = getLoggerLogLevel(name); + const prefix = getLogPrefix(params); const logLevelOverride = logLevelOverrides.find((override) => - override.regex.test(loggerName) + override.regex.test(name) ); if (logLevelOverride) { logger.setLevel(logLevelOverride.level); } - const fmtLogMessage = (args: string[], ...msg: any[]) => { - if (args.length) { - return [`${args.join(":")}: `, ...msg]; - } - return msg; - }; + const fmtLogMessage = (msg: any[]) => (prefix ? [prefix, ...msg] : msg); + const customLogger: LoggerWithMethods = { - trace: (...msg: any[]) => logger.trace(...fmtLogMessage(args, ...msg)), - debug: (...msg: any[]) => logger.debug(...fmtLogMessage(args, ...msg)), - info: (...msg: any[]) => logger.info(...fmtLogMessage(args, ...msg)), - warn: (...msg: any[]) => logger.warn(...fmtLogMessage(args, ...msg)), - error: (...msg: any[]) => logger.error(...fmtLogMessage(args, ...msg)), + trace: (...msg: any[]) => logger.trace(...fmtLogMessage(msg)), + debug: (...msg: any[]) => logger.debug(...fmtLogMessage(msg)), + info: (...msg: any[]) => logger.info(...fmtLogMessage(msg)), + warn: (...msg: any[]) => logger.warn(...fmtLogMessage(msg)), + error: (...msg: any[]) => logger.error(...fmtLogMessage(msg)), }; + return customLogger; }