Improve and reduce logs (#84)

* chore: print info on number of blocks to sync * chore: reduce severity of logs for handler * chore: delete useless log * chore: reduce logs and print TX instead of params, to make logs smaller * chore: simplify log * feat: add env vars * chore: improve logging * chore: improve handling of conditional order params * chore: reduce logs * chore: decrease log * chore: add simulation for tenderly if error (raise from debug to error) * chore: test deploy docker * fix: fix issue with types * 1.0.1-rc.0
cowprotocol · Oct 4, 2023 · 3454b48 · 3454b48
1 parent 0a17ada
commit 3454b48
Show file tree

Hide file tree

Showing 10 changed files with 82 additions and 87 deletions.
diff --git a/.github/workflows/docker.yml b/.github/workflows/docker.yml
@@ -4,6 +4,8 @@ on:
   push:
     branches: [main]
     tags: [v*]
+  pull_request:
+    types: [opened, synchronize]
 
 jobs:
   docker:

diff --git a/package.json b/package.json
@@ -1,7 +1,7 @@
 {
   "name": "@cowprotocol/watch-tower",
   "license": "GPL-3.0-or-later",
-  "version": "0.2.0",
+  "version": "1.0.1-rc.0",
   "description": "A standalone watch tower, keeping an eye on Composable Cows  👀🐮",
   "author": {
     "name": "Cow Protocol"

diff --git a/src/domain/addContract.ts b/src/domain/addContract.ts
@@ -1,4 +1,4 @@
-import { getLogger } from "../utils";
+import { toConditionalOrderParams, getLogger } from "../utils";
 import { BytesLike, ethers } from "ethers";
 
 import {
@@ -15,6 +15,7 @@ import {
 
 import { isComposableCowCompatible, handleExecutionError } from "../utils";
 import { ChainContext } from "./chainContext";
+import { ConditionalOrderParams } from "@cowprotocol/cow-sdk";
 
 /**
  * Listens to these events on the `ComposableCoW` contract:
@@ -34,7 +35,7 @@ async function _addContract(
   context: ChainContext,
   event: ConditionalOrderCreatedEvent
 ) {
-  const log = getLogger("addContract:_addContract");
+  const log = getLogger("addContract");
   const composableCow = ComposableCoW__factory.createInterface();
   const { provider, registry } = context;
   const { transactionHash: tx, blockNumber } = event;
@@ -64,7 +65,7 @@ async function _addContract(
   hasErrors ||= error;
 
   if (numContractsAdded > 0) {
-    log.info(`Added ${numContractsAdded} contracts`);
+    log.debug(`Added ${numContractsAdded} contracts`);
 
     // Write the registry to disk. Don't catch errors, let them bubble up
     await registry.write();
@@ -103,7 +104,7 @@ export async function _registerNewOrder(
       add(
         eventLog.transactionHash,
         owner,
-        params,
+        toConditionalOrderParams(params),
         null,
         eventLog.address,
         registry
@@ -143,7 +144,7 @@ export async function _registerNewOrder(
           add(
             event.transactionHash,
             owner,
-            decodedOrder[1],
+            toConditionalOrderParams(decodedOrder[1]),
             { merkleRoot: root, path: decodedOrder[0] },
             eventLog.address,
             registry
@@ -175,7 +176,7 @@ export async function _registerNewOrder(
 export function add(
   tx: string,
   owner: Owner,
-  params: IConditionalOrder.ConditionalOrderParamsStruct,
+  params: ConditionalOrderParams,
   proof: Proof | null,
   composableCow: string,
   registry: Registry
@@ -202,7 +203,7 @@ export function add(
     if (!exists) {
       conditionalOrders?.add({
         tx,
-        params,
+        params: { handler, salt, staticInput },
         proof,
         orders: new Map(),
         composableCow,

diff --git a/src/domain/chainContext.ts b/src/domain/chainContext.ts
@@ -87,6 +87,7 @@ export class ChainContext {
       : this.deploymentBlock;
     let currentBlockNumber = await provider.getBlockNumber();
 
+    let printSyncInfo = true; // Print sync info only once
     let plan: ReplayPlan = {};
     let toBlock: "latest" | number = 0;
     do {
@@ -97,18 +98,29 @@ export class ChainContext {
           currentBlockNumber = await provider.getBlockNumber();
           toBlock = toBlock > currentBlockNumber ? currentBlockNumber : toBlock;
 
-          log.trace(
+          log.debug(
             `Reaching tip of chain, current block number: ${currentBlockNumber}`
           );
         }
 
-        log.trace(
+        if (printSyncInfo && typeof toBlock === "number") {
+          printSyncInfo = false;
+          log.info(
+            `🔄 Start sync with from block ${fromBlock} to ${toBlock}. Pending ${
+              toBlock - fromBlock
+            } blocks (~${Math.ceil((toBlock - fromBlock) / pageSize)} pages)`
+          );
+        }
+
+        log.debug(
           `Processing events from block ${fromBlock} to block ${toBlock}`
         );
 
         const events = await pollContractForEvents(fromBlock, toBlock, this);
 
-        log.trace(`Found ${events.length} events`);
+        if (events.length > 0) {
+          log.debug(`Found ${events.length} events`);
+        }
 
         // process the events
         for (const event of events) {
@@ -171,7 +183,9 @@ export class ChainContext {
     } while (!this.inSync);
 
     log.info(
-      oneShot ? "Chain watcher is in sync" : "Chain watcher is warmed up"
+      `💚 ${
+        oneShot ? "Chain watcher is in sync" : "Chain watcher is warmed up"
+      }`
     );
     log.debug(`Last processed block: ${this.registry.lastProcessedBlock}`);
 
@@ -191,9 +205,9 @@ export class ChainContext {
    */
   private async runBlockWatcher() {
     const { provider, registry, chainId } = this;
-    const log = getLogger(`chainContext:warmUp:${chainId}`);
+    const log = getLogger(`chainContext:runBlockWatcher:${chainId}`);
     // Watch for new blocks
-    log.info("Running block watcher");
+    log.info("👀 Start block watcher");
     let lastBlockReceived = 0;
     let timeLastBlockProcessed = new Date().getTime();
     provider.on("block", async (blockNumber: number) => {
@@ -271,24 +285,19 @@ async function processBlock(
     const receipt = await provider.getTransactionReceipt(event.transactionHash);
     if (receipt) {
       // run action
-      log.info(`Running "addContract" action for TX ${event.transactionHash}`);
+      log.debug(`Running "addContract" action for TX ${event.transactionHash}`);
       const result = await addContract(context, event)
         .then(() => true)
         .catch((e) => {
           hasErrors = true;
           log.error(`Error running "addContract" action for TX:`, e);
           return false;
         });
-      log.info(
-        `Result of "addContract" action for TX ${
-          event.transactionHash
-        }: ${_formatResult(result)}`
-      );
+      log.info(`Result of "addContract": ${_formatResult(result)}`);
     }
   }
 
   // run action
-  log.info(`Run "checkForAndPlaceOrder" action for block ${blockNumber}`);
   const result = await checkForAndPlaceOrder(
     context,
     block,
@@ -301,7 +310,7 @@ async function processBlock(
       log.error(`Error running "checkForAndPlaceOrder" action`);
       return false;
     });
-  log.info(
+  log.debug(
     `Result of "checkForAndPlaceOrder" action for block ${blockNumber}: ${_formatResult(
       result
     )}`

diff --git a/src/domain/checkForAndPlaceOrder.ts b/src/domain/checkForAndPlaceOrder.ts
@@ -23,7 +23,6 @@ import {
   SINGLE_ORDER_NOT_AUTHED_SELECTOR,
   formatStatus,
   getLogger,
-  handleExecutionError,
   parseCustomError,
   pollConditionalOrder,
 } from "../utils";
@@ -74,23 +73,6 @@ export async function checkForAndPlaceOrder(
   block: ethers.providers.Block,
   blockNumberOverride?: number,
   blockTimestampOverride?: number
-) {
-  return _checkForAndPlaceOrder(
-    context,
-    block,
-    blockNumberOverride,
-    blockTimestampOverride
-  ).catch(handleExecutionError);
-}
-
-/**
- * Asynchronous version of checkForAndPlaceOrder. It will process all the orders, and will throw an error at the end if there was at least one error
- */
-async function _checkForAndPlaceOrder(
-  context: ChainContext,
-  block: ethers.providers.Block,
-  blockNumberOverride?: number,
-  blockTimestampOverride?: number
 ) {
   const { chainId, registry, provider } = context;
   const { ownerOrders, numOrders } = registry;
@@ -102,18 +84,17 @@ async function _checkForAndPlaceOrder(
   let ownerCounter = 0;
   let orderCounter = 0;
 
-  const logPrefix = `checkForAndPlaceOrder:_checkForAndPlaceOrder:${chainId}:${blockNumber}`;
+  const logPrefix = `checkForAndPlaceOrder:${chainId}:${blockNumber}`;
   const log = getLogger(logPrefix);
-  log.info(`Number of orders: ${numOrders}`);
+  log.debug(`Total number of orders: ${numOrders}`);
 
   for (const [owner, conditionalOrders] of ownerOrders.entries()) {
     ownerCounter++;
     const log = getLogger(`${logPrefix}:${ownerCounter}`);
     const ordersPendingDelete = [];
     // enumerate all the `ConditionalOrder`s for a given owner
-    log.info(
-      `Process owner ${owner} (${conditionalOrders.size} orders)`,
-      registry.numOrders
+    log.debug(
+      `Process owner ${owner} (${conditionalOrders.size} orders): ${registry.numOrders}`
     );
     for (const conditionalOrder of conditionalOrders) {
       orderCounter++;
@@ -196,14 +177,7 @@ async function _checkForAndPlaceOrder(
         pollResult.result +
         (isError && pollResult.reason ? `. Reason: ${pollResult.reason}` : "");
 
-      const logLevel =
-        pollResult.result === PollResultCode.SUCCESS
-          ? "info"
-          : pollResult.result === PollResultCode.UNEXPECTED_ERROR
-          ? "error"
-          : "warn";
-
-      log[logLevel](
+      log[unexpectedError ? "error" : "info"](
         `Check conditional order result: ${getEmojiByPollResult(
           pollResult?.result
         )} ${resultDescription}`
@@ -218,12 +192,9 @@ async function _checkForAndPlaceOrder(
     // Delete orders we don't want to keep watching
     for (const conditionalOrder of ordersPendingDelete) {
       const deleted = conditionalOrders.delete(conditionalOrder);
-      const action = deleted ? "Deleted" : "Fail to delete";
+      const action = deleted ? "Stop Watching" : "Failed to stop watching";
 
-      log.info(
-        `${action} conditional order with params:`,
-        conditionalOrder.params
-      );
+      log.debug(`${action} conditional order from TX ${conditionalOrder.tx}`);
     }
   }
 
@@ -239,14 +210,15 @@ async function _checkForAndPlaceOrder(
   // and we want to crash if there's an error
   await registry.write();
 
-  log.info(`Remaining orders: `, registry.numOrders);
+  log.debug(
+    `Total orders after processing all conditional orders: ${registry.numOrders}`
+  );
 
   // Throw execution error if there was at least one error
   if (hasErrors) {
     throw Error(`At least one unexpected error processing conditional orders`);
   }
 }
-
 async function _processConditionalOrder(
   owner: string,
   conditionalOrder: ConditionalOrder,
@@ -262,13 +234,6 @@ async function _processConditionalOrder(
     `checkForAndPlaceOrder:_processConditionalOrder:${orderRef}`
   );
   try {
-    // TODO: Fix model and delete the explicit cast: https://github.com/cowprotocol/tenderly-watch-tower/issues/18
-    const [handler, salt, staticInput] = conditionalOrder.params as any as [
-      string,
-      string,
-      string
-    ];
-
     const proof = conditionalOrder.proof
       ? conditionalOrder.proof.path.map((c) => c.toString())
       : [];
@@ -285,14 +250,9 @@ async function _processConditionalOrder(
       },
       provider,
     };
-    const conditionalOrderParams = {
-      handler,
-      staticInput,
-      salt,
-    };
     let pollResult = await pollConditionalOrder(
       pollParams,
-      conditionalOrderParams,
+      conditionalOrder.params,
       orderRef
     );
 
@@ -470,7 +430,7 @@ async function _placeOrder(params: {
       );
 
       if (isSuccess) {
-        log.info(`All good! continuing with warnings...`);
+        log.debug(`All good! continuing with warnings...`);
         return { result: PollResultCode.SUCCESS };
       } else {
         return handleErrorResult;
@@ -563,10 +523,6 @@ async function _pollLegacy(
     [owner, conditionalOrder.params, offchainInput, proof]
   );
 
-  log.debug(
-    `Simulate: https://dashboard.tenderly.co/gp-v2/watch-tower-prod/simulator/new?network=${chainId}&contractAddress=${to}&rawFunctionInput=${data}`
-  );
-
   try {
     const lowLevelCall = await multicall.callStatic.aggregate3Value([
       {
@@ -595,6 +551,10 @@ async function _pollLegacy(
       signature,
     };
   } catch (error: any) {
+    log.error(
+      `Error on CALL to getTradeableOrderWithSignature. Simulate: https://dashboard.tenderly.co/gp-v2/watch-tower-prod/simulator/new?network=${chainId}&contractAddress=${to}&rawFunctionInput=${data}`
+    );
+
     // Print and handle the error
     // We need to decide if the error is final or not (if a re-attempt might help). If it doesn't, we delete the order
     return _handleGetTradableOrderCall(error, owner, orderRef);

diff --git a/src/index.ts b/src/index.ts
@@ -1,3 +1,5 @@
+import "dotenv/config";
+
 import { program, Option } from "@commander-js/extra-typings";
 import { ReplayTxOptions } from "./types";
 import { dumpDb, replayBlock, replayTx, run } from "./commands";

diff --git a/src/types/index.ts b/src/types/index.ts
@@ -36,6 +36,8 @@ export interface DumpDbOptions extends LogOptions {
   chainId: number;
 }
 
+export type ToBlock = "latest" | number;
+
 export * from "./model";
 export * from "./generated";
 export * from "./generated/ComposableCoW";
diff --git a/src/types/model.ts b/src/types/model.ts
@@ -2,11 +2,8 @@ import Slack = require("node-slack");
 
 import { BytesLike } from "ethers";
 
-import type {
-  ConditionalOrderCreatedEvent,
-  IConditionalOrder,
-} from "./generated/ComposableCoW";
-import { PollResult } from "@cowprotocol/cow-sdk";
+import type { ConditionalOrderCreatedEvent } from "./generated/ComposableCoW";
+import { ConditionalOrderParams, PollResult } from "@cowprotocol/cow-sdk";
 import { DBService } from "../utils";
 
 // Standardise the storage key
@@ -59,7 +56,7 @@ export type ConditionalOrder = {
   /**
    * The parameters of the conditional order
    */
-  params: IConditionalOrder.ConditionalOrderParamsStruct; // TODO: We should not use the raw `ConditionalOrderParamsStruct` instead we should do some plain object `ConditionalOrderParams` with the handler,salt,staticInput as properties. See https://github.com/cowprotocol/tenderly-watch-tower/issues/18
+  params: ConditionalOrderParams;
 
   /**
    * The merkle proof if the conditional order is belonging to a merkle root