HttpClient: log request and response (#3913)

* Http client: log request & response * Review PR Co-authored-by: dapplion <[email protected]>
ChainSafe · Apr 15, 2022 · 8898b2a · 8898b2a
1 parent 540ec10
commit 8898b2a
Show file tree

Hide file tree

Showing 15 changed files with 52 additions and 34 deletions.
diff --git a/packages/api/README.md b/packages/api/README.md
@@ -15,9 +15,9 @@ Typescript REST client for the [Ethereum Consensus API spec](https://github.com/
 import {getClient} from "@chainsafe/lodestar-api";
 import {config} from "@chainsafe/lodestar-config/default";
 
-const api = getClient(config, {
+const api = getClient({
   baseUrl: "http://localhost:9596",
-});
+}, {config});
 
 api.beacon
   .getStateValidator(

diff --git a/packages/api/src/client/index.ts b/packages/api/src/client/index.ts
@@ -1,6 +1,6 @@
 import {IChainForkConfig} from "@chainsafe/lodestar-config";
 import {Api} from "../interface";
-import {IHttpClient, HttpClient, HttpClientOptions, HttpError} from "./utils";
+import {IHttpClient, HttpClient, HttpClientOptions, HttpClientModules, HttpError} from "./utils";
 export {HttpClient, HttpClientOptions, HttpError};
 
 import * as beacon from "./beacon";
@@ -12,11 +12,17 @@ import * as lodestar from "./lodestar";
 import * as node from "./node";
 import * as validator from "./validator";
 
+type ClientModules = HttpClientModules & {
+  config: IChainForkConfig;
+  httpClient?: IHttpClient;
+};
+
 /**
  * REST HTTP client for all routes
  */
-export function getClient(config: IChainForkConfig, opts: HttpClientOptions, httpClient?: IHttpClient): Api {
-  if (!httpClient) httpClient = new HttpClient(opts);
+export function getClient(opts: HttpClientOptions, modules: ClientModules): Api {
+  const {config} = modules;
+  const httpClient = modules.httpClient ?? new HttpClient(opts, modules);
 
   return {
     beacon: beacon.getClient(config, httpClient),

diff --git a/packages/api/src/client/utils/httpClient.ts b/packages/api/src/client/utils/httpClient.ts
@@ -1,6 +1,6 @@
 import {fetch} from "cross-fetch";
 import {AbortSignal, AbortController} from "@chainsafe/abort-controller";
-import {ErrorAborted, TimeoutError} from "@chainsafe/lodestar-utils";
+import {ErrorAborted, ILogger, TimeoutError} from "@chainsafe/lodestar-utils";
 import {ReqGeneric, RouteDef} from "../../utils";
 import {stringifyQuery, urlJoin} from "./format";
 import {Metrics} from "./metrics";
@@ -39,8 +39,11 @@ export type HttpClientOptions = {
   getAbortSignal?: () => AbortSignal | undefined;
   /** Override fetch function */
   fetch?: typeof fetch;
-  /** Optional metrics */
-  metrics?: null | Metrics;
+};
+
+export type HttpClientModules = {
+  logger?: ILogger;
+  metrics?: Metrics;
 };
 
 export class HttpClient implements IHttpClient {
@@ -49,17 +52,19 @@ export class HttpClient implements IHttpClient {
   private readonly getAbortSignal?: () => AbortSignal | undefined;
   private readonly fetch: typeof fetch;
   private readonly metrics: null | Metrics;
+  private readonly logger: null | ILogger;
 
   /**
    * timeoutMs = config.params.SECONDS_PER_SLOT * 1000
    */
-  constructor(opts: HttpClientOptions) {
+  constructor(opts: HttpClientOptions, {logger, metrics}: HttpClientModules = {}) {
     this.baseUrl = opts.baseUrl;
     // A higher default timeout, validator will sets its own shorter timeoutMs
     this.timeoutMs = opts.timeoutMs ?? 60_000;
     this.getAbortSignal = opts.getAbortSignal;
     this.fetch = opts.fetch ?? fetch;
-    this.metrics = opts.metrics ?? null;
+    this.metrics = metrics ?? null;
+    this.logger = logger ?? null;
   }
 
   async json<T>(opts: FetchOpts): Promise<T> {
@@ -90,6 +95,8 @@ export class HttpClient implements IHttpClient {
       const headers = opts.headers || {};
       if (opts.body) headers["Content-Type"] = "application/json";
 
+      this.logger?.debug("HttpClient request", {routeId});
+
       const res = await this.fetch(url, {
         method: opts.method,
         headers: headers as Record<string, string>,
@@ -102,6 +109,8 @@ export class HttpClient implements IHttpClient {
         throw new HttpError(`${res.statusText}: ${getErrorMessage(errBody)}`, res.status, url);
       }
 
+      this.logger?.debug("HttpClient response", {routeId});
+
       return await getBody(res);
     } catch (e) {
       if (isAbortedError(e as Error)) {

diff --git a/packages/beacon-state-transition/test/perf/analyzeBlocks.ts b/packages/beacon-state-transition/test/perf/analyzeBlocks.ts
@@ -16,7 +16,7 @@ import {getInfuraBeaconUrl} from "./infura";
 // aggregationBitsAvg: 87.88991645944512
 
 const network = "mainnet";
-const client = getClient(config, {baseUrl: getInfuraBeaconUrl(network)});
+const client = getClient({baseUrl: getInfuraBeaconUrl(network)}, {config});
 
 async function run(): Promise<void> {
   const {data: headBlock} = await client.beacon.getBlockHeader("head");

diff --git a/packages/beacon-state-transition/test/perf/analyzeEpochs.ts b/packages/beacon-state-transition/test/perf/analyzeEpochs.ts
@@ -81,7 +81,7 @@ async function analyzeEpochs(network: NetworkName, fromEpoch?: number): Promise<
 
   const baseUrl = getInfuraBeaconUrl(network);
   // Long timeout to download states
-  const client = getClient(config, {baseUrl, timeoutMs: 5 * 60 * 1000});
+  const client = getClient({baseUrl, timeoutMs: 5 * 60 * 1000}, {config});
 
   // Start at epoch 1 since 0 will go and fetch state at slot -1
   const maxEpoch = fromEpoch ?? Math.max(1, ...currCsv.map((row) => row.epoch));

diff --git a/packages/beacon-state-transition/test/perf/util.ts b/packages/beacon-state-transition/test/perf/util.ts
@@ -508,7 +508,7 @@ export async function getNetworkCachedState(
   if (fs.existsSync(filepath)) {
     stateSsz = fs.readFileSync(filepath);
   } else {
-    const client = getClient(config, {baseUrl: getInfuraBeaconUrl(network), timeoutMs: timeout ?? 300_000});
+    const client = getClient({baseUrl: getInfuraBeaconUrl(network), timeoutMs: timeout ?? 300_000}, {config});
     stateSsz =
       computeEpochAtSlot(slot) < config.ALTAIR_FORK_EPOCH
         ? await client.debug.getState(String(slot), "ssz")

diff --git a/packages/cli/src/cmds/account/cmds/validator/slashingProtection/utils.ts b/packages/cli/src/cmds/account/cmds/validator/slashingProtection/utils.ts
@@ -30,7 +30,7 @@ export async function getGenesisValidatorsRoot(args: IGlobalArgs & ISlashingProt
   const server = args.server;
 
   const config = getBeaconConfigFromArgs(args);
-  const api = getClient(config, {baseUrl: server});
+  const api = getClient({baseUrl: server}, {config});
   const genesis = await api.beacon.getGenesis();
 
   if (genesis !== undefined) {

diff --git a/packages/cli/src/networks/index.ts b/packages/cli/src/networks/index.ts
@@ -147,7 +147,7 @@ export async function fetchWeakSubjectivityState(
 ): Promise<{wsState: BeaconStateAllForks; wsCheckpoint: Checkpoint}> {
   try {
     let wsCheckpoint;
-    const api = getClient(config, {baseUrl: weakSubjectivityServerUrl});
+    const api = getClient({baseUrl: weakSubjectivityServerUrl}, {config});
     if (weakSubjectivityCheckpoint) {
       wsCheckpoint = getCheckpointFromArg(weakSubjectivityCheckpoint);
     } else {

diff --git a/packages/light-client/src/index.ts b/packages/light-client/src/index.ts
@@ -142,7 +142,7 @@ export class Lightclient {
     this.logger = logger ?? getLcLoggerConsole();
 
     this.beaconApiUrl = beaconApiUrl;
-    this.api = getClient(config, {baseUrl: beaconApiUrl});
+    this.api = getClient({baseUrl: beaconApiUrl}, {config});
 
     const periodCurr = computeSyncPeriodAtSlot(snapshot.header.slot);
     this.syncCommitteeByPeriod.set(periodCurr, {
@@ -172,7 +172,7 @@ export class Lightclient {
     genesisData: GenesisData;
     checkpointRoot: phase0.Checkpoint["root"];
   }): Promise<Lightclient> {
-    const api = getClient(config, {baseUrl: beaconApiUrl});
+    const api = getClient({baseUrl: beaconApiUrl}, {config});
 
     // Fetch snapshot with proof at the trusted block root
     const {data: snapshotWithProof} = await api.lightclient.getSnapshot(toHexString(checkpointRoot));

diff --git a/packages/light-client/test/getGenesisData.ts b/packages/light-client/test/getGenesisData.ts
@@ -16,7 +16,7 @@ const networksInInfura: NetworkName[] = ["mainnet", "prater"];
 async function getGenesisData(): Promise<void> {
   for (const network of networksInInfura) {
     const baseUrl = getInfuraBeaconUrl(network);
-    const api = getClient(config, {baseUrl});
+    const api = getClient({baseUrl}, {config});
     const {data: genesis} = await api.beacon.getGenesis();
     console.log(network, {
       genesisTime: Number(genesis.genesisTime),

diff --git a/packages/lodestar/test/e2e/api/impl/beacon/state/endpoint.test.ts b/packages/lodestar/test/e2e/api/impl/beacon/state/endpoint.test.ts
@@ -65,7 +65,7 @@ describe("lodestar / api / impl / state", function () {
 
       await Promise.all(validators.map((validator) => validator.start()));
 
-      const client = getClient(config, {baseUrl: `http://127.0.0.1:${restPort}`}).beacon;
+      const client = getClient({baseUrl: `http://127.0.0.1:${restPort}`}, {config}).beacon;
 
       const response = await client.getStateValidators("head");
       expect(response.data.length).to.be.equal(validatorCount);
@@ -101,7 +101,7 @@ describe("lodestar / api / impl / state", function () {
 
       await Promise.all(validators.map((validator) => validator.start()));
 
-      const client = getClient(config, {baseUrl: `http://127.0.0.1:${restPort}`}).beacon;
+      const client = getClient({baseUrl: `http://127.0.0.1:${restPort}`}, {config}).beacon;
 
       const response = await client.getStateValidators("head", {
         id: [filterPubKey],

diff --git a/packages/lodestar/test/e2e/sync/endpoint.test.ts b/packages/lodestar/test/e2e/sync/endpoint.test.ts
@@ -52,7 +52,7 @@ describe("lodestar / sync", function () {
 
       afterEachCallbacks.push(() => bn.close());
 
-      const client = getClient(config, {baseUrl: "http://127.0.0.1:9596"}).node;
+      const client = getClient({baseUrl: "http://127.0.0.1:9596"}, {config}).node;
 
       // expect headSlot and syncDistance to be string
       await expect(client.getSyncingStatus()).to.eventually.be.deep.equal({

diff --git a/packages/lodestar/test/scripts/blsPubkeyBytesFrequency.ts b/packages/lodestar/test/scripts/blsPubkeyBytesFrequency.ts
@@ -110,7 +110,7 @@ async function writePubkeys(): Promise<void> {
 `);
   }
 
-  const client = getClient(config, {baseUrl});
+  const client = getClient({baseUrl}, {config});
 
   const {data: state} = await client.debug.getStateV2("finalized");
 

diff --git a/packages/validator/src/validator.ts b/packages/validator/src/validator.ts
@@ -65,13 +65,15 @@ export class Validator {
 
     const api =
       typeof opts.api === "string"
-        ? getClient(config, {
-            baseUrl: opts.api,
-            // Validator would need the beacon to respond within the slot
-            timeoutMs: config.SECONDS_PER_SLOT * 1000,
-            getAbortSignal: this.getAbortSignal,
-            metrics: metrics?.restApiClient,
-          })
+        ? getClient(
+            {
+              baseUrl: opts.api,
+              // Validator would need the beacon to respond within the slot
+              timeoutMs: config.SECONDS_PER_SLOT * 1000,
+              getAbortSignal: this.getAbortSignal,
+            },
+            {config, logger, metrics: metrics?.restApiClient}
+          )
         : opts.api;
 
     const clock = new Clock(config, logger, {genesisTime: Number(genesis.genesisTime)});
@@ -127,22 +129,23 @@ export class Validator {
     metrics?: Metrics | null
   ): Promise<Validator> {
     const {config} = opts.dbOps;
+    const {logger} = opts;
     const api =
       typeof opts.api === "string"
         ? // This new api instance can make do with default timeout as a faster timeout is
           // not necessary since this instance won't be used for validator duties
-          getClient(config, {baseUrl: opts.api, getAbortSignal: () => signal})
+          getClient({baseUrl: opts.api, getAbortSignal: () => signal}, {config, logger})
         : opts.api;
 
     const genesis = await waitForGenesis(api, opts.logger, signal);
-    opts.logger.info("Genesis available");
+    logger.info("Genesis available");
 
     const {data: externalSpecJson} = await api.config.getSpec();
     assertEqualParams(config, externalSpecJson);
-    opts.logger.info("Verified node and validator have same config");
+    logger.info("Verified node and validator have same config");
 
     await assertEqualGenesis(opts, genesis);
-    opts.logger.info("Verified node and validator have same genesisValidatorRoot");
+    logger.info("Verified node and validator have same genesisValidatorRoot");
 
     return new Validator(opts, genesis, metrics);
   }

diff --git a/packages/validator/test/utils/apiStub.ts b/packages/validator/test/utils/apiStub.ts
@@ -5,7 +5,7 @@ import {config} from "@chainsafe/lodestar-config/default";
 export function getApiClientStub(
   sandbox: SinonSandbox = sinon
 ): Api & {[K in keyof Api]: sinon.SinonStubbedInstance<Api[K]>} {
-  const api = getClient(config, {baseUrl: ""});
+  const api = getClient({baseUrl: ""}, {config});
 
   return {
     beacon: sandbox.stub(api.beacon),