Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Move winston NodeJS transports to cli package #4509

Merged
merged 13 commits into from
Sep 6, 2022
56 changes: 0 additions & 56 deletions packages/beacon-node/src/node/loggerOptions.ts

This file was deleted.

40 changes: 31 additions & 9 deletions packages/beacon-node/src/node/nodejs.ts
Original file line number Diff line number Diff line change
Expand Up @@ -56,6 +56,19 @@ export enum BeaconNodeStatus {
closed = "closed",
}

enum LoggerModule {
api = "api",
backfill = "backfill",
chain = "chain",
eth1 = "eth1",
metrics = "metrics",
network = "network",
/** validator monitor */
vmon = "vmon",
rest = "rest",
sync = "sync",
}

/**
* The main Beacon Node class. Contains various components for getting and processing data from the
* Ethereum Consensus ecosystem as well as systems for getting beacon node metadata.
Expand Down Expand Up @@ -132,7 +145,13 @@ export class BeaconNode {

let metrics = null;
if (opts.metrics.enabled) {
metrics = createMetrics(opts.metrics, config, anchorState, logger.child({module: "VMON"}), metricsRegistries);
metrics = createMetrics(
opts.metrics,
config,
anchorState,
logger.child({module: LoggerModule.vmon}),
metricsRegistries
);
initBeaconMetrics(metrics, anchorState);
// Since the db is instantiated before this, metrics must be injected manually afterwards
db.setMetrics(metrics.db);
Expand All @@ -141,15 +160,15 @@ export class BeaconNode {
const chain = new BeaconChain(opts.chain, {
config,
db,
logger: logger.child(opts.logger.chain),
logger: logger.child({module: LoggerModule.chain}),
processShutdownCallback,
metrics,
anchorState,
eth1: initializeEth1ForBlockProduction(opts.eth1, {
config,
db,
metrics,
logger: logger.child(opts.logger.eth1),
logger: logger.child({module: LoggerModule.eth1}),
signal,
}),
executionEngine: initializeExecutionEngine(opts.executionEngine, {metrics, signal}),
Expand All @@ -164,7 +183,7 @@ export class BeaconNode {
const network = new Network(opts.network, {
config,
libp2p,
logger: logger.child(opts.logger.network),
logger: logger.child({module: LoggerModule.network}),
metrics,
chain,
reqRespHandlers: getReqRespHandlers({db, chain}),
Expand All @@ -177,7 +196,7 @@ export class BeaconNode {
metrics,
network,
wsCheckpoint,
logger: logger.child(opts.logger.sync),
logger: logger.child({module: LoggerModule.sync}),
});

const backfillSync =
Expand All @@ -190,14 +209,14 @@ export class BeaconNode {
network,
wsCheckpoint,
anchorState,
logger: logger.child(opts.logger.backfill),
logger: logger.child({module: LoggerModule.backfill}),
signal,
})
: null;

const api = getApi(opts.api, {
config,
logger: logger.child(opts.logger.api),
logger: logger.child({module: LoggerModule.api}),
db,
sync,
network,
Expand All @@ -206,15 +225,18 @@ export class BeaconNode {
});

const metricsServer = metrics
? new HttpMetricsServer(opts.metrics, {register: metrics.register, logger: logger.child(opts.logger.metrics)})
? new HttpMetricsServer(opts.metrics, {
register: metrics.register,
logger: logger.child({module: LoggerModule.metrics}),
})
: undefined;
if (metricsServer) {
await metricsServer.start();
}

const restApi = new BeaconRestApiServer(opts.api.rest, {
config,
logger: logger.child(opts.logger.api),
logger: logger.child({module: LoggerModule.rest}),
api,
metrics: metrics ? metrics.apiRest : null,
});
Expand Down
3 changes: 0 additions & 3 deletions packages/beacon-node/src/node/options.ts
Original file line number Diff line number Diff line change
Expand Up @@ -11,7 +11,6 @@ import {
ExecutionBuilderOpts,
defaultExecutionBuilderOpts,
} from "../execution/index.js";
import {defaultLoggerOptions, IBeaconLoggerOptions} from "./loggerOptions.js";
// Re-export so the CLI doesn't need to depend on lodestar-api
export {allNamespaces} from "../api/rest/index.js";

Expand All @@ -22,7 +21,6 @@ export interface IBeaconNodeOptions {
eth1: Eth1Options;
executionEngine: ExecutionEngineOpts;
executionBuilder: ExecutionBuilderOpts;
logger: IBeaconLoggerOptions;
metrics: MetricsOptions;
network: INetworkOptions;
sync: SyncOptions;
Expand All @@ -35,7 +33,6 @@ export const defaultOptions: IBeaconNodeOptions = {
eth1: defaultEth1Options,
executionEngine: defaultExecutionEngineOpts,
executionBuilder: defaultExecutionBuilderOpts,
logger: defaultLoggerOptions,
metrics: defaultMetricsOptions,
network: defaultNetworkOptions,
sync: defaultSyncOptions,
Expand Down
6 changes: 3 additions & 3 deletions packages/beacon-node/test/e2e/chain/lightclient.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -113,7 +113,7 @@ describe("chain / lightclient", function () {
});
}).then(async (head) => {
// Initialize lightclient
loggerLC.important("Initializing lightclient", {slot: head.slot});
loggerLC.info("Initializing lightclient", {slot: head.slot});
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

.important API is not used anymore in production and forces creators of custom loggers to add it


const lightclient = await Lightclient.initializeFromCheckpointRoot({
config: bn.config,
Expand All @@ -130,7 +130,7 @@ describe("chain / lightclient", function () {
lightclient.stop();
});

loggerLC.important("Initialized lightclient", {headSlot: lightclient.getHead().slot});
loggerLC.info("Initialized lightclient", {headSlot: lightclient.getHead().slot});
lightclient.start();

return new Promise<void>((resolve, reject) => {
Expand Down Expand Up @@ -166,7 +166,7 @@ describe("chain / lightclient", function () {

const promiseTillFinalization = new Promise<void>((resolve) => {
bn.chain.emitter.on(ChainEvent.finalized, (checkpoint) => {
loggerNodeA.important("Node A emitted finalized checkpoint event", {epoch: checkpoint.epoch});
loggerNodeA.info("Node A emitted finalized checkpoint event", {epoch: checkpoint.epoch});
if (checkpoint.epoch >= finalizedEpochToReach) {
resolve();
}
Expand Down
Original file line number Diff line number Diff line change
@@ -1,11 +1,10 @@
import {expect} from "chai";
import {config} from "@lodestar/config/default";
import {fromHexString} from "@chainsafe/ssz";
import {allForks, phase0, ssz} from "@lodestar/types";
import {ssz} from "@lodestar/types";
import {BeaconDb} from "../../../../../../src/db/index.js";
import {generateSignedBlock} from "../../../../../utils/block.js";
import {testLogger} from "../../../../../utils/logger.js";
import {BlockArchiveBatchPutBinaryItem} from "../../../../../../src/db/repositories/index.js";
import {startTmpBeaconDb} from "../../../../../utils/db.js";

describe("BlockArchiveRepository", function () {
Expand Down Expand Up @@ -70,49 +69,4 @@ describe("BlockArchiveRepository", function () {
savedBlock2.message.slot = sampleBlock.message.slot;
expect(ssz.phase0.SignedBeaconBlock.equals(savedBlock1, savedBlock2)).to.equal(true);
});

it("batchPutBinary should be faster than batchPut", async () => {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is not a test but a very old performance test with winston profiler. Removed as it's not even tracked

// increase length to test performance
const signedBlocks = Array.from({length: 1000}, (_, i) => {
const signedBlock = sampleBlock;
signedBlock.message.slot = i;
return signedBlock;
});
// persist to block db
await Promise.all(signedBlocks.map((signedBlock: phase0.SignedBeaconBlock) => db.block.add(signedBlock)));
const blockSummaries = signedBlocks.map(toBatchPutBinaryItem);
// old way
logger.profile("batchPut");
const savedBlocks = notNull(
await Promise.all(blockSummaries.map((summary) => db.block.get(summary.blockRoot as Uint8Array)))
);
await db.blockArchive.batchPut(savedBlocks.map((block) => ({key: block.message.slot, value: block})));
logger.profile("batchPut");
logger.profile("batchPutBinary");
const blockBinaries = notNull(
await Promise.all(blockSummaries.map((summary) => db.block.getBinary(summary.blockRoot as Uint8Array)))
);
await db.blockArchive.batchPutBinary(
blockSummaries.map((summary, i) => ({
...summary,
value: blockBinaries[i],
}))
);
logger.profile("batchPutBinary");
});
});

function notNull<T>(arr: (T | null)[]): T[] {
for (const item of arr) if (item === null) throw Error("null item");
return arr as T[];
}

function toBatchPutBinaryItem(signedBlock: allForks.SignedBeaconBlock): BlockArchiveBatchPutBinaryItem {
return {
key: signedBlock.message.slot,
value: ssz.phase0.SignedBeaconBlock.serialize(signedBlock) as Buffer,
slot: signedBlock.message.slot,
blockRoot: config.getForkTypes(signedBlock.message.slot).BeaconBlock.hashTreeRoot(signedBlock.message),
parentRoot: signedBlock.message.parentRoot,
};
}
2 changes: 1 addition & 1 deletion packages/beacon-node/test/e2e/sync/finalizedSync.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -65,7 +65,7 @@ describe("sync / finalized sync", function () {
afterEachCallbacks.push(() => bn.close());

await waitForEvent<phase0.Checkpoint>(bn.chain.emitter, ChainEvent.finalized, 240000);
loggerNodeA.important("Node A emitted finalized checkpoint event");
loggerNodeA.info("Node A emitted finalized checkpoint event");

const bn2 = await getDevBeaconNode({
params: beaconParams,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -74,7 +74,7 @@ describe("sync / unknown block sync", function () {
afterEachCallbacks.push(() => bn.close());

await waitForEvent<phase0.Checkpoint>(bn.chain.emitter, ChainEvent.checkpoint, 240000);
loggerNodeA.important("Node A emitted checkpoint event");
loggerNodeA.info("Node A emitted checkpoint event");

const bn2 = await getDevBeaconNode({
params: testParams,
Expand Down
6 changes: 3 additions & 3 deletions packages/beacon-node/test/e2e/sync/wss.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -84,16 +84,16 @@ describe("Start from WSS", function () {
try {
await finalizedEventistener;
await waitForEvent<phase0.Checkpoint>(bn.chain.emitter, ChainEvent.finalized, timeout);
loggerNodeA.important("\n\nNode A finalized\n\n");
loggerNodeA.info("\n\nNode A finalized\n\n");
} catch (e) {
(e as Error).message = `Node A failed to finalize: ${(e as Error).message}`;
throw e;
}

const checkpointSyncUrl = "http://127.0.0.1:19596";
loggerNodeB.important("Fetching weak subjectivity state ", {checkpointSyncUrl});
loggerNodeB.info("Fetching weak subjectivity state ", {checkpointSyncUrl});
const {wsState, wsCheckpoint} = await fetchWeakSubjectivityState(config, loggerNodeB, {checkpointSyncUrl});
loggerNodeB.important("Fetched wss state");
loggerNodeB.info("Fetched wss state");

const bnStartingFromWSS = await getDevBeaconNode({
params: {...testParams, ALTAIR_FORK_EPOCH: Infinity},
Expand Down
4 changes: 2 additions & 2 deletions packages/beacon-node/test/unit/metrics/utils.ts
Original file line number Diff line number Diff line change
@@ -1,10 +1,10 @@
import {config} from "@lodestar/config/default";
import {ssz} from "@lodestar/types";
import {WinstonLogger} from "@lodestar/utils";
import {createMetrics, IMetrics} from "../../../src/metrics/index.js";
import {testLogger} from "../../utils/logger.js";

export function createMetricsTest(): IMetrics {
const state = ssz.phase0.BeaconState.defaultViewDU();
const logger = new WinstonLogger();
const logger = testLogger();
return createMetrics({enabled: true, port: 0}, config, state, logger);
}
Original file line number Diff line number Diff line change
@@ -1,13 +1,14 @@
import {expect} from "chai";
import PeerId from "peer-id";
import sinon, {SinonStubbedInstance} from "sinon";
import {WinstonLogger} from "@lodestar/utils";
import {IPeerRpcScoreStore, PeerAction, PeerRpcScoreStore} from "../../../../../src/network/index.js";
import {defaultNetworkOptions} from "../../../../../src/network/options.js";
import {InboundRateLimiter} from "../../../../../src/network/reqresp/response/rateLimiter.js";
import {Method, RequestTypedContainer} from "../../../../../src/network/reqresp/types.js";
import {testLogger} from "../../../../utils/logger.js";

describe("ResponseRateLimiter", () => {
const logger = testLogger();
let inboundRateLimiter: InboundRateLimiter;
const sandbox = sinon.createSandbox();
let peerRpcScoresStub: IPeerRpcScoreStore & SinonStubbedInstance<PeerRpcScoreStore>;
Expand All @@ -16,7 +17,7 @@ describe("ResponseRateLimiter", () => {
peerRpcScoresStub = sandbox.createStubInstance(PeerRpcScoreStore) as IPeerRpcScoreStore &
SinonStubbedInstance<PeerRpcScoreStore>;
inboundRateLimiter = new InboundRateLimiter(defaultNetworkOptions, {
logger: new WinstonLogger(),
logger,
peerRpcScores: peerRpcScoresStub,
metrics: null,
});
Expand Down Expand Up @@ -140,7 +141,7 @@ describe("ResponseRateLimiter", () => {
const startMem = process.memoryUsage().heapUsed;

const rateLimiter = new InboundRateLimiter(defaultNetworkOptions, {
logger: new WinstonLogger(),
logger,
peerRpcScores: peerRpcScoresStub,
metrics: null,
});
Expand Down
18 changes: 12 additions & 6 deletions packages/beacon-node/test/utils/logger.ts
Original file line number Diff line number Diff line change
@@ -1,5 +1,6 @@
/* eslint-disable @typescript-eslint/no-unsafe-member-access, @typescript-eslint/no-unsafe-assignment */
import {WinstonLogger, LogLevel, TransportType, TransportOpts, TimestampFormat} from "@lodestar/utils";
import winston from "winston";
import {createWinstonLogger, ILogger, LogLevel, TimestampFormat} from "@lodestar/utils";
export {LogLevel};

export type TestLoggerOpts = {
Expand All @@ -16,15 +17,20 @@ export type TestLoggerOpts = {
* VERBOSE=1 mocha .ts
* ```
*/
export function testLogger(module?: string, opts?: TestLoggerOpts): WinstonLogger {
const transports: TransportOpts[] = [
{type: TransportType.console, level: getLogLevelFromEnvs() || opts?.logLevel || LogLevel.error},
export function testLogger(module?: string, opts?: TestLoggerOpts): ILogger {
const transports: winston.transport[] = [
new winston.transports.Console({level: getLogLevelFromEnvs() || opts?.logLevel || LogLevel.error}),
];
if (opts?.logFile) {
transports.push({type: TransportType.file, filename: opts.logFile, level: LogLevel.debug});
transports.push(
new winston.transports.File({
level: LogLevel.debug,
filename: opts.logFile,
})
);
}

return new WinstonLogger({module, ...opts}, transports);
return createWinstonLogger({module, ...opts}, transports);
}

function getLogLevelFromEnvs(): LogLevel | null {
Expand Down