feat(apps/price_pusher)!: switch to structured logger via pino (#1714)

* feat(apps/price_pusher)!: switch to structured logger via pino

This change switches from `console` to `pino` for logging that is a
structured logger and allows us to have json formatted loggers. In
adition to just that change, pino does an amazing job at logging the
errors by including all their data + the stacktrace.

This change does minimal change to the log level and the `console.log`
is changed to info or debug level based on my judgement.

This change is marked as breaking because it breaks any reliability/ops
based on the logs.

* fix: address review comments

* fix: add @solana/web3.js deps as its used

* refactor: make it more configurable

Author: ali-behjati

apps/price_pusher/README.md

@@ -83,14 +83,14 @@ To run the price pusher, please run the following commands, replacing the comman
 
 ```sh
 # Please run the two following commands once from the root of the repo to build the code.
-npm install
+pnpm install
 pnpm exec lerna run build --scope @pythnetwork/price-pusher --include-dependencies
 
 # Navigate to the price_pusher folder
 cd apps/price_pusher
 
 # For EVM
-npm run start -- evm --endpoint wss://example-rpc.com \
+pnpm run start evm --endpoint wss://example-rpc.com \
     --pyth-contract-address 0xff1a0f4744e8582DF...... \
     --price-service-endpoint https://example-hermes-rpc.com \
     --price-config-file "path/to/price-config.beta.sample.yaml" \
@@ -100,7 +100,7 @@ npm run start -- evm --endpoint wss://example-rpc.com \
     [--override-gas-price-multiplier 1.1]
 
 # For Injective
-npm run start -- injective --grpc-endpoint https://grpc-endpoint.com \
+pnpm run start injective --grpc-endpoint https://grpc-endpoint.com \
     --pyth-contract-address inj1z60tg0... --price-service-endpoint "https://example-hermes-rpc.com" \
     --price-config-file "path/to/price-config.beta.sample.yaml" \
     --mnemonic-file "path/to/mnemonic.txt" \
@@ -110,7 +110,7 @@ npm run start -- injective --grpc-endpoint https://grpc-endpoint.com \
     [--polling-frequency 5]
 
 # For Aptos
-npm run start -- aptos --endpoint https://fullnode.testnet.aptoslabs.com/v1 \
+pnpm run start aptos --endpoint https://fullnode.testnet.aptoslabs.com/v1 \
     --pyth-contract-address 0x7e783b349d3e89cf5931af376ebeadbfab855b3fa239b7ada8f5a92fbea6b387 \
     --price-service-endpoint "https://example-hermes-rpc.com" \
     --price-config-file "path/to/price-config.beta.sample.yaml" \
@@ -119,7 +119,7 @@ npm run start -- aptos --endpoint https://fullnode.testnet.aptoslabs.com/v1 \
     [--polling-frequency 5]
 
 # For Sui
-npm run start -- sui \
+pnpm run start sui \
   --endpoint https://sui-testnet-rpc.allthatnode.com \
   --pyth-package-id 0x975e063f398f720af4f33ec06a927f14ea76ca24f7f8dd544aa62ab9d5d15f44 \
   --pyth-state-id 0xd8afde3a48b4ff7212bd6829a150f43f59043221200d63504d981f62bff2e27a \
@@ -134,7 +134,7 @@ npm run start -- sui \
   [--num-gas-objects 30]
 
 # For Near
-npm run start -- near \
+pnpm run start near \
   --node-url https://rpc.testnet.near.org \
   --network testnet \
   --account-id payer.testnet \
@@ -146,7 +146,7 @@ npm run start -- near \
   [--polling-frequency 5]
 
 # For Solana, using Jito (recommended)
-npm run start -- solana \
+pnpm run start solana \
   --endpoint https://api.mainnet-beta.solana.com \
   --keypair-file ./id.json \
   --shard-id 1 \
@@ -161,7 +161,7 @@ npm run start -- solana \
   [--polling-frequency 5]
 
 # For Solana, using Solana RPC
-npm run start -- solana \
+pnpm run start solana \
   --endpoint https://api.devnet.solana.com \
   --keypair-file ./id.json \
   --shard-id 1 \
@@ -184,23 +184,35 @@ docker run public.ecr.aws/pyth-network/xc-price-pusher:v<version> -- <above-argu
 To know more about the arguments the price-pusher accepts. You can run:
 
 ```sh
-npm run start -- --help
+pnpm run start --help
 
 # for specific network run
-npm run start -- {network} --help
+pnpm run start {network} --help
 ```
 
+### Logging
+
+By default, the logging is set to `info`. You can change the logging level by passing the argument `--log-level` with the desired level.
+The available levels are `error`, `warn`, `info`, `debug`, and `trace`. Also, the logs have JSON format. If you wish to run the code with
+human-readable logs, you can pipe the output of the program to `pino-pretty`. See the example below for more information on how to do this.
+
+You can configure the log level of some of the modules of the price pusher as well. The available modules are PriceServiceConnection, which
+is responsible for connecting to the Hermes price service, and Controller, which is responsible for checking the prices from the Hermes
+and the on-chain Pyth contract and deciding whether to push a new price. You can configure the log level of these modules by passing the
+`--price-service-connection-log-level` and `--controller-log-level` arguments, respectively.
+
 ### Example
 
 For example, to push `BTC/USD` and `BNB/USD` prices on Fantom testnet, run the following command:
 
 ```sh
-npm run dev -- evm \
+pnpm run dev evm \
   --endpoint https://endpoints.omniatech.io/v1/fantom/testnet/public \
   --pyth-contract-address 0x5744Cbf430D99456a0A8771208b674F27f8EF0Fb \
   --price-service-endpoint https://hermes.pyth.network \
   --mnemonic-file "./mnemonic" \
-  --price-config-file "./price-config.stable.sample.yaml"
+  --price-config-file "./price-config.stable.sample.yaml" \
+  | pnpm exec pino-pretty # Make logs human-readable
 ```
 
 [`price-config.stable.sample.yaml`](./price-config.stable.sample.yaml) contains configuration for `BTC/USD`
@@ -210,7 +222,7 @@ contains the same configuration for `BTC/USD` and `BNB/USD` on Pyth beta data so
 You can also provide a config file instead of providing command line options, run the following command:
 
 ```sh
-npm run start -- injective --config "./config.injective.sample.json"
+pnpm run start injective --config "./config.injective.sample.json"
 ```
 
 [`config.injective.sample.json`](./config.injective.sample.json) contains configuration to publish on Injective testnet.

apps/price_pusher/package.json

@@ -1,6 +1,6 @@
 {
   "name": "@pythnetwork/price-pusher",
-  "version": "6.8.0",
+  "version": "7.0.0-alpha",
   "description": "Pyth Price Pusher",
   "homepage": "https://pyth.network",
   "main": "lib/index.js",
@@ -46,6 +46,7 @@
     "@typescript-eslint/parser": "^6.0.0",
     "eslint": "^8.13.0",
     "jest": "^29.7.0",
+    "pino-pretty": "^11.2.1",
     "prettier": "^2.6.2",
     "ts-jest": "^29.1.1",
     "ts-node": "^10.9.1",
@@ -62,11 +63,14 @@
     "@pythnetwork/pyth-solana-receiver": "workspace:*",
     "@pythnetwork/pyth-sui-js": "workspace:*",
     "@pythnetwork/solana-utils": "workspace:*",
+    "@solana/web3.js": "^1.93.0",
     "@truffle/hdwallet-provider": "^2.1.3",
+    "@types/pino": "^7.0.5",
     "aptos": "^1.8.5",
     "jito-ts": "^3.0.1",
     "joi": "^17.6.0",
     "near-api-js": "^3.0.2",
+    "pino": "^9.2.0",
     "web3": "^1.8.1",
     "web3-core": "^1.8.1",
     "web3-eth-contract": "^1.8.1",

apps/price_pusher/src/aptos/aptos.ts

@@ -7,17 +7,19 @@ import {
 import { AptosAccount, AptosClient } from "aptos";
 import { DurationInSeconds } from "../utils";
 import { PriceServiceConnection } from "@pythnetwork/price-service-client";
+import { Logger } from "pino";
 
 export class AptosPriceListener extends ChainPriceListener {
   constructor(
     private pythModule: string,
     private endpoint: string,
     priceItems: PriceItem[],
+    private logger: Logger,
     config: {
       pollingFrequency: DurationInSeconds;
     }
   ) {
-    super("aptos", config.pollingFrequency, priceItems);
+    super(config.pollingFrequency, priceItems);
   }
 
   async getOnChainPriceInfo(priceId: string): Promise<PriceInfo | undefined> {
@@ -46,7 +48,7 @@ export class AptosPriceListener extends ChainPriceListener {
       const price =
         multiplier * Number(priceItemRes.price_feed.price.price.magnitude);
 
-      console.log(
+      this.logger.debug(
         `Polled an Aptos on-chain price for feed ${this.priceIdToAlias.get(
           priceId
         )} (${priceId}).`
@@ -57,11 +59,11 @@ export class AptosPriceListener extends ChainPriceListener {
         conf: priceItemRes.price_feed.price.conf,
         publishTime: Number(priceItemRes.price_feed.price.timestamp),
       };
-    } catch (e) {
-      console.error(
-        `Polling Aptos on-chain price for ${priceId} failed. Error:`
+    } catch (err) {
+      this.logger.error(
+        err,
+        `Polling Aptos on-chain price for ${priceId} failed.`
       );
-      console.error(e);
       return undefined;
     }
   }
@@ -88,6 +90,7 @@ export class AptosPricePusher implements IPricePusher {
 
   constructor(
     private priceServiceConnection: PriceServiceConnection,
+    private logger: Logger,
     private pythContractAddress: string,
     private endpoint: string,
     private mnemonic: string,
@@ -126,9 +129,8 @@ export class AptosPricePusher implements IPricePusher {
     try {
       // get the latest VAAs for updatePriceFeed and then push them
       priceFeedUpdateData = await this.getPriceFeedsUpdateData(priceIds);
-    } catch (e) {
-      console.error("Error fetching the latest vaas to push");
-      console.error(e);
+    } catch (err) {
+      this.logger.error(err, "Error fetching the latest vaas to push.");
       return;
     }
 
@@ -158,7 +160,10 @@ export class AptosPricePusher implements IPricePusher {
       const signedTx = await client.signTransaction(account, rawTx);
       const pendingTx = await client.submitTransaction(signedTx);
 
-      console.log("Successfully broadcasted txHash:", pendingTx.hash);
+      this.logger.debug(
+        { hash: pendingTx.hash },
+        "Successfully broadcasted tx."
+      );
 
       // Sometimes broadcasted txs don't make it on-chain and they cause our sequence number
       // to go out of sync. Missing transactions are rare and we don't want this check to block
@@ -167,9 +172,8 @@ export class AptosPricePusher implements IPricePusher {
       this.waitForTransactionConfirmation(client, pendingTx.hash);
 
       return;
-    } catch (e: any) {
-      console.error("Error executing messages");
-      console.error(e);
+    } catch (err: any) {
+      this.logger.error(err, "Error executing messages");
 
       // Reset the sequence number to re-sync it (in case that was the issue)
       this.lastSequenceNumber = undefined;
@@ -189,10 +193,12 @@ export class AptosPricePusher implements IPricePusher {
         timeoutSecs: 10,
       });
 
-      console.log(`Transaction with txHash "${txHash}" confirmed.`);
-    } catch (e) {
-      console.error(`Transaction with txHash "${txHash}" failed to confirm.`);
-      console.error(e);
+      this.logger.info({ hash: txHash }, `Transaction confirmed.`);
+    } catch (err) {
+      this.logger.error(
+        { err, hash: txHash },
+        `Transaction failed to confirm.`
+      );
 
       this.lastSequenceNumber = undefined;
     }
@@ -218,7 +224,7 @@ export class AptosPricePusher implements IPricePusher {
           this.lastSequenceNumber = Number(
             (await client.getAccount(account.address())).sequence_number
           );
-          console.log(
+          this.logger.debug(
             `Fetched account sequence number: ${this.lastSequenceNumber}`
           );
           return this.lastSequenceNumber;

apps/price_pusher/src/aptos/command.ts

@@ -11,6 +11,7 @@ import {
   APTOS_ACCOUNT_HD_PATH,
 } from "./aptos";
 import { AptosAccount } from "aptos";
+import pino from "pino";
 
 export default {
   command: "aptos",
@@ -37,6 +38,9 @@ export default {
     ...options.pythContractAddress,
     ...options.pollingFrequency,
     ...options.pushingFrequency,
+    ...options.logLevel,
+    ...options.priceServiceConnectionLogLevel,
+    ...options.controllerLogLevel,
   },
   handler: function (argv: any) {
     // FIXME: type checks for this
@@ -49,44 +53,50 @@ export default {
       pushingFrequency,
       pollingFrequency,
       overrideGasPriceMultiplier,
+      logLevel,
+      priceServiceConnectionLogLevel,
+      controllerLogLevel,
     } = argv;
 
+    const logger = pino({ level: logLevel });
+
     const priceConfigs = readPriceConfigFile(priceConfigFile);
     const priceServiceConnection = new PriceServiceConnection(
       priceServiceEndpoint,
       {
-        logger: {
-          // Log only warnings and errors from the price service client
-          info: () => undefined,
-          warn: console.warn,
-          error: console.error,
-          debug: () => undefined,
-          trace: () => undefined,
-        },
+        logger: logger.child(
+          { module: "PriceServiceConnection" },
+          { level: priceServiceConnectionLogLevel }
+        ),
       }
     );
+
     const mnemonic = fs.readFileSync(mnemonicFile, "utf-8").trim();
     const account = AptosAccount.fromDerivePath(
       APTOS_ACCOUNT_HD_PATH,
       mnemonic
     );
-    console.log(`Pushing from account address: ${account.address()}`);
+    logger.info(`Pushing from account address: ${account.address()}`);
 
     const priceItems = priceConfigs.map(({ id, alias }) => ({ id, alias }));
 
     const pythListener = new PythPriceListener(
       priceServiceConnection,
-      priceItems
+      priceItems,
+      logger.child({ module: "PythPriceListener" })
     );
 
     const aptosListener = new AptosPriceListener(
       pythContractAddress,
       endpoint,
       priceItems,
+      logger.child({ module: "AptosPriceListener" }),
       { pollingFrequency }
     );
+
     const aptosPusher = new AptosPricePusher(
       priceServiceConnection,
+      logger.child({ module: "AptosPricePusher" }),
       pythContractAddress,
       endpoint,
       mnemonic,
@@ -98,6 +108,7 @@ export default {
       pythListener,
       aptosListener,
       aptosPusher,
+      logger.child({ module: "Controller" }, { level: controllerLogLevel }),
       { pushingFrequency }
     );