From 8898b2ad9ead504db8c7971729b3ccd634efebf0 Mon Sep 17 00:00:00 2001 From: tuyennhv Date: Fri, 15 Apr 2022 08:19:07 +0700 Subject: [PATCH] HttpClient: log request and response (#3913) * Http client: log request & response * Review PR Co-authored-by: dapplion <35266934+dapplion@users.noreply.github.com> --- packages/api/README.md | 4 +-- packages/api/src/client/index.ts | 12 ++++++--- packages/api/src/client/utils/httpClient.ts | 19 ++++++++++---- .../test/perf/analyzeBlocks.ts | 2 +- .../test/perf/analyzeEpochs.ts | 2 +- .../beacon-state-transition/test/perf/util.ts | 2 +- .../validator/slashingProtection/utils.ts | 2 +- packages/cli/src/networks/index.ts | 2 +- packages/light-client/src/index.ts | 4 +-- packages/light-client/test/getGenesisData.ts | 2 +- .../api/impl/beacon/state/endpoint.test.ts | 4 +-- .../lodestar/test/e2e/sync/endpoint.test.ts | 2 +- .../test/scripts/blsPubkeyBytesFrequency.ts | 2 +- packages/validator/src/validator.ts | 25 +++++++++++-------- packages/validator/test/utils/apiStub.ts | 2 +- 15 files changed, 52 insertions(+), 34 deletions(-) diff --git a/packages/api/README.md b/packages/api/README.md index 6cd968db9a89..eac0c9aa4572 100644 --- 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 index 5d61bea1c3dc..6d33562131eb 100644 --- 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 index 53057b5357ac..f13be746fda8 100644 --- 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(opts: FetchOpts): Promise { @@ -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, @@ -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 index a897ab55cbee..170f9c00f0f4 100644 --- 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 { 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 index 5aaf1f8b3444..20e39f0c37de 100644 --- 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 index 1701fc0bfe02..3fac02e2f573 100644 --- 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 index cf15b089f593..c2d5325ede34 100644 --- 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 index dfddd02cd901..dc224af3755a 100644 --- 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 index 503edd3f9ca8..ec3c4dab9abf 100644 --- 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 { - 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 index 2679932e901b..86421140e67b 100644 --- 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 { 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 index 2ce3754105d1..5ec94d9e97e2 100644 --- 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 index 42d3bcf01612..52cbdcf47f1f 100644 --- 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 index e72f2371e0a6..f6995548cdba 100644 --- a/packages/lodestar/test/scripts/blsPubkeyBytesFrequency.ts +++ b/packages/lodestar/test/scripts/blsPubkeyBytesFrequency.ts @@ -110,7 +110,7 @@ async function writePubkeys(): Promise { `); } - 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 index 6f493eef3663..50d6e806b7ec 100644 --- 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 { 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 index 01bf8512a9f6..40eb6b493f88 100644 --- 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} { - const api = getClient(config, {baseUrl: ""}); + const api = getClient({baseUrl: ""}, {config}); return { beacon: sandbox.stub(api.beacon),