diff --git a/packages/beacon-node/package.json b/packages/beacon-node/package.json index 756f65c84dd0..70774ea6646e 100644 --- a/packages/beacon-node/package.json +++ b/packages/beacon-node/package.json @@ -124,6 +124,7 @@ "@lodestar/db": "^1.8.0", "@lodestar/fork-choice": "^1.8.0", "@lodestar/light-client": "^1.8.0", + "@lodestar/logger": "^1.8.0", "@lodestar/params": "^1.8.0", "@lodestar/reqresp": "^1.8.0", "@lodestar/state-transition": "^1.8.0", diff --git a/packages/beacon-node/src/network/discv5/index.ts b/packages/beacon-node/src/network/discv5/index.ts index 8d6d08951ca0..b4f41ce7a8e9 100644 --- a/packages/beacon-node/src/network/discv5/index.ts +++ b/packages/beacon-node/src/network/discv5/index.ts @@ -5,14 +5,14 @@ import {exportToProtobuf} from "@libp2p/peer-id-factory"; import {createKeypairFromPeerId, ENR, ENRData, IKeypair, SignableENR} from "@chainsafe/discv5"; import {spawn, Thread, Worker} from "@chainsafe/threads"; import {chainConfigFromJson, chainConfigToJson, BeaconConfig} from "@lodestar/config"; -import {Logger} from "@lodestar/utils"; +import {LoggerNode} from "@lodestar/logger/node"; import {NetworkCoreMetrics} from "../core/metrics.js"; import {Discv5WorkerApi, Discv5WorkerData, LodestarDiscv5Opts} from "./types.js"; export type Discv5Opts = { peerId: PeerId; discv5: LodestarDiscv5Opts; - logger: Logger; + logger: LoggerNode; config: BeaconConfig; metrics?: NetworkCoreMetrics; }; @@ -29,7 +29,7 @@ type Discv5WorkerStatus = * Wrapper class abstracting the details of discv5 worker instantiation and message-passing */ export class Discv5Worker extends (EventEmitter as {new (): StrictEventEmitter}) { - private logger: Logger; + private logger: LoggerNode; private status: Discv5WorkerStatus; private keypair: IKeypair; @@ -53,6 +53,7 @@ export class Discv5Worker extends (EventEmitter as {new (): StrictEventEmitter[1]); diff --git a/packages/beacon-node/src/network/discv5/types.ts b/packages/beacon-node/src/network/discv5/types.ts index fed7be318ca8..5630ed17a667 100644 --- a/packages/beacon-node/src/network/discv5/types.ts +++ b/packages/beacon-node/src/network/discv5/types.ts @@ -1,6 +1,7 @@ import {Discv5, ENRData, SignableENRData} from "@chainsafe/discv5"; import {Observable} from "@chainsafe/threads/observable"; import {ChainConfig} from "@lodestar/config"; +import {LoggerNodeOpts} from "@lodestar/logger/node"; // TODO export IDiscv5Config so we don't need this convoluted type type Discv5Config = Parameters<(typeof Discv5)["create"]>[0]["config"]; @@ -22,6 +23,7 @@ export interface Discv5WorkerData { metrics: boolean; chainConfig: ChainConfig; genesisValidatorsRoot: Uint8Array; + loggerOpts: LoggerNodeOpts; } /** diff --git a/packages/beacon-node/src/network/discv5/worker.ts b/packages/beacon-node/src/network/discv5/worker.ts index 5f2eba45bd62..e54ff2abb805 100644 --- a/packages/beacon-node/src/network/discv5/worker.ts +++ b/packages/beacon-node/src/network/discv5/worker.ts @@ -6,6 +6,7 @@ import {expose} from "@chainsafe/threads/worker"; import {Observable, Subject} from "@chainsafe/threads/observable"; import {createKeypairFromPeerId, Discv5, ENR, ENRData, SignableENR, SignableENRData} from "@chainsafe/discv5"; import {createBeaconConfig, BeaconConfig} from "@lodestar/config"; +import {getNodeLogger} from "@lodestar/logger/node"; import {RegistryMetricCreator} from "../../metrics/index.js"; import {collectNodeJSMetrics} from "../../metrics/nodeJsMetrics.js"; import {ENRKey} from "../metadata.js"; @@ -55,6 +56,8 @@ const workerData = worker.workerData as Discv5WorkerData; // eslint-disable-next-line @typescript-eslint/strict-boolean-expressions if (!workerData) throw Error("workerData must be defined"); +const logger = getNodeLogger(workerData.loggerOpts); + // Set up metrics, nodejs and discv5-specific let metricsRegistry: RegistryMetricCreator | undefined; let enrRelevanceMetric: Gauge<"status"> | undefined; @@ -134,3 +137,9 @@ const module: Discv5WorkerApi = { }; expose(module); + +logger.info("discv5 worker started", { + peerId: peerId.toString(), + listenAddr: workerData.bindAddr, + initialENR: workerData.enr, +}); diff --git a/packages/beacon-node/src/network/network.ts b/packages/beacon-node/src/network/network.ts index 61938c49b566..2f617841df46 100644 --- a/packages/beacon-node/src/network/network.ts +++ b/packages/beacon-node/src/network/network.ts @@ -2,8 +2,9 @@ import {Connection} from "@libp2p/interface-connection"; import {PeerId} from "@libp2p/interface-peer-id"; import {Multiaddr} from "@multiformats/multiaddr"; import {BeaconConfig} from "@lodestar/config"; -import {Logger, sleep, toHex} from "@lodestar/utils"; +import {sleep, toHex} from "@lodestar/utils"; import {ForkName} from "@lodestar/params"; +import {LoggerNode} from "@lodestar/logger/node"; import {computeEpochAtSlot, computeTimeAtSlot} from "@lodestar/state-transition"; import {Epoch, phase0, allForks} from "@lodestar/types"; import {routes} from "@lodestar/api"; @@ -42,7 +43,7 @@ type NetworkModules = { opts: NetworkOptions; config: BeaconConfig; libp2p: Libp2p; - logger: Logger; + logger: LoggerNode; chain: IBeaconChain; signal: AbortSignal; peersData: PeersData; @@ -63,7 +64,7 @@ export type NetworkInitModules = { config: BeaconConfig; peerId: PeerId; peerStoreDir?: string; - logger: Logger; + logger: LoggerNode; metrics: Metrics | null; chain: IBeaconChain; reqRespHandlers: ReqRespHandlers; @@ -88,7 +89,7 @@ export class Network implements INetwork { private readonly statusCache: LocalStatusCache; private readonly libp2p: Libp2p; private readonly gossipsub: Eth2Gossipsub; - private readonly logger: Logger; + private readonly logger: LoggerNode; private readonly config: BeaconConfig; private readonly clock: IClock; private readonly chain: IBeaconChain; diff --git a/packages/beacon-node/src/network/peers/discover.ts b/packages/beacon-node/src/network/peers/discover.ts index 203d58052e55..93a633606bc4 100644 --- a/packages/beacon-node/src/network/peers/discover.ts +++ b/packages/beacon-node/src/network/peers/discover.ts @@ -2,9 +2,10 @@ import {PeerId} from "@libp2p/interface-peer-id"; import {Multiaddr} from "@multiformats/multiaddr"; import {PeerInfo} from "@libp2p/interface-peer-info"; import {BeaconConfig} from "@lodestar/config"; -import {Logger, pruneSetToMax, sleep} from "@lodestar/utils"; +import {pruneSetToMax, sleep} from "@lodestar/utils"; import {ENR} from "@chainsafe/discv5"; import {ATTESTATION_SUBNET_COUNT, SYNC_COMMITTEE_SUBNET_COUNT} from "@lodestar/params"; +import {LoggerNode} from "@lodestar/logger/node"; import {NetworkCoreMetrics} from "../core/metrics.js"; import {Libp2p} from "../interface.js"; import {ENRKey, SubnetType} from "../metadata.js"; @@ -30,7 +31,7 @@ export type PeerDiscoveryModules = { libp2p: Libp2p; peerRpcScores: IPeerRpcScoreStore; metrics: NetworkCoreMetrics | null; - logger: Logger; + logger: LoggerNode; config: BeaconConfig; }; @@ -76,7 +77,7 @@ export class PeerDiscovery { private libp2p: Libp2p; private peerRpcScores: IPeerRpcScoreStore; private metrics: NetworkCoreMetrics | null; - private logger: Logger; + private logger: LoggerNode; private config: BeaconConfig; private cachedENRs = new Map(); private randomNodeQuery: QueryStatus = {code: QueryStatusCode.NotActive}; diff --git a/packages/beacon-node/src/network/peers/peerManager.ts b/packages/beacon-node/src/network/peers/peerManager.ts index 381c99c4d3fa..4e632dac9bfb 100644 --- a/packages/beacon-node/src/network/peers/peerManager.ts +++ b/packages/beacon-node/src/network/peers/peerManager.ts @@ -4,7 +4,7 @@ import {BitArray} from "@chainsafe/ssz"; import {SYNC_COMMITTEE_SUBNET_COUNT} from "@lodestar/params"; import {BeaconConfig} from "@lodestar/config"; import {allForks, altair, phase0} from "@lodestar/types"; -import {Logger} from "@lodestar/utils"; +import {LoggerNode} from "@lodestar/logger/node"; import {GoodByeReasonCode, GOODBYE_KNOWN_CODES, Libp2pEvent} from "../../constants/index.js"; import {NetworkCoreMetrics} from "../core/metrics.js"; import {NetworkEvent, INetworkEventBus} from "../events.js"; @@ -83,7 +83,7 @@ export type PeerManagerOpts = { export type PeerManagerModules = { libp2p: Libp2p; - logger: Logger; + logger: LoggerNode; metrics: NetworkCoreMetrics | null; reqResp: IReqRespBeaconNode; gossip: Eth2Gossipsub; @@ -115,7 +115,7 @@ enum RelevantPeerStatus { */ export class PeerManager { private libp2p: Libp2p; - private logger: Logger; + private logger: LoggerNode; private metrics: NetworkCoreMetrics | null; private reqResp: IReqRespBeaconNode; private gossipsub: Eth2Gossipsub; diff --git a/packages/beacon-node/src/node/nodejs.ts b/packages/beacon-node/src/node/nodejs.ts index a370aba2608f..439698085fac 100644 --- a/packages/beacon-node/src/node/nodejs.ts +++ b/packages/beacon-node/src/node/nodejs.ts @@ -4,7 +4,7 @@ import {Registry} from "prom-client"; import {PeerId} from "@libp2p/interface-peer-id"; import {BeaconConfig} from "@lodestar/config"; import {phase0} from "@lodestar/types"; -import {Logger} from "@lodestar/utils"; +import {LoggerNode} from "@lodestar/logger/node"; import {Api, ServerApi} from "@lodestar/api"; import {BeaconStateAllForks} from "@lodestar/state-transition"; import {ProcessShutdownCallback} from "@lodestar/validator"; @@ -45,7 +45,7 @@ export type BeaconNodeInitModules = { opts: IBeaconNodeOptions; config: BeaconConfig; db: IBeaconDb; - logger: Logger; + logger: LoggerNode; processShutdownCallback: ProcessShutdownCallback; peerId: PeerId; peerStoreDir?: string; diff --git a/packages/beacon-node/test/e2e/api/impl/lightclient/endpoint.test.ts b/packages/beacon-node/test/e2e/api/impl/lightclient/endpoint.test.ts index 2f8491b26908..e4e767107ecb 100644 --- a/packages/beacon-node/test/e2e/api/impl/lightclient/endpoint.test.ts +++ b/packages/beacon-node/test/e2e/api/impl/lightclient/endpoint.test.ts @@ -23,7 +23,7 @@ describe("lightclient api", function () { const chainConfig: ChainConfig = {...chainConfigDef, SECONDS_PER_SLOT, ALTAIR_FORK_EPOCH}; const genesisValidatorsRoot = Buffer.alloc(32, 0xaa); const config = createBeaconConfig(chainConfig, genesisValidatorsRoot); - const testLoggerOpts: TestLoggerOpts = {logLevel: LogLevel.info}; + const testLoggerOpts: TestLoggerOpts = {level: LogLevel.info}; const loggerNodeA = testLogger("Node-A", testLoggerOpts); const validatorCount = 2; diff --git a/packages/beacon-node/test/e2e/api/lodestar/lodestar.test.ts b/packages/beacon-node/test/e2e/api/lodestar/lodestar.test.ts index 49ccbeee6115..11f2566a29e7 100644 --- a/packages/beacon-node/test/e2e/api/lodestar/lodestar.test.ts +++ b/packages/beacon-node/test/e2e/api/lodestar/lodestar.test.ts @@ -38,7 +38,7 @@ describe("api / impl / validator", function () { const genesisValidatorsRoot = Buffer.alloc(32, 0xaa); const config = createBeaconConfig(chainConfig, genesisValidatorsRoot); - const testLoggerOpts: TestLoggerOpts = {logLevel: LogLevel.info}; + const testLoggerOpts: TestLoggerOpts = {level: LogLevel.info}; const loggerNodeA = testLogger("Node-A", testLoggerOpts); const bn = await getDevBeaconNode({ @@ -90,7 +90,7 @@ describe("api / impl / validator", function () { const genesisValidatorsRoot = Buffer.alloc(32, 0xaa); const config = createBeaconConfig(chainConfig, genesisValidatorsRoot); - const testLoggerOpts: TestLoggerOpts = {logLevel: LogLevel.info}; + const testLoggerOpts: TestLoggerOpts = {level: LogLevel.info}; const loggerNodeA = testLogger("Node-A", testLoggerOpts); const bn = await getDevBeaconNode({ diff --git a/packages/beacon-node/test/e2e/chain/lightclient.test.ts b/packages/beacon-node/test/e2e/chain/lightclient.test.ts index 533e8cc8091d..470f56d63669 100644 --- a/packages/beacon-node/test/e2e/chain/lightclient.test.ts +++ b/packages/beacon-node/test/e2e/chain/lightclient.test.ts @@ -3,7 +3,7 @@ import {ChainConfig} from "@lodestar/config"; import {ssz, altair} from "@lodestar/types"; import {JsonPath, toHexString, fromHexString} from "@chainsafe/ssz"; import {computeDescriptor, TreeOffsetProof} from "@chainsafe/persistent-merkle-tree"; -import {TimestampFormatCode} from "@lodestar/utils"; +import {TimestampFormatCode} from "@lodestar/logger"; import {EPOCHS_PER_SYNC_COMMITTEE_PERIOD, SLOTS_PER_EPOCH} from "@lodestar/params"; import {Lightclient} from "@lodestar/light-client"; import {computeStartSlotAtEpoch} from "@lodestar/state-transition"; @@ -57,7 +57,7 @@ describe("chain / lightclient", function () { const genesisTime = Math.floor(Date.now() / 1000) + genesisSlotsDelay * testParams.SECONDS_PER_SLOT; const testLoggerOpts: TestLoggerOpts = { - logLevel: LogLevel.info, + level: LogLevel.info, timestampFormat: { format: TimestampFormatCode.EpochSlot, genesisTime, @@ -67,7 +67,7 @@ describe("chain / lightclient", function () { }; const loggerNodeA = testLogger("Node", testLoggerOpts); - const loggerLC = testLogger("LC", {...testLoggerOpts, logLevel: LogLevel.debug}); + const loggerLC = testLogger("LC", {...testLoggerOpts, level: LogLevel.debug}); const bn = await getDevBeaconNode({ params: testParams, @@ -92,7 +92,7 @@ describe("chain / lightclient", function () { validatorClientCount, startIndex: 0, useRestApi: false, - testLoggerOpts: {...testLoggerOpts, logLevel: LogLevel.error}, + testLoggerOpts: {...testLoggerOpts, level: LogLevel.error}, }); afterEachCallbacks.push(async () => { diff --git a/packages/beacon-node/test/e2e/doppelganger/doppelganger.test.ts b/packages/beacon-node/test/e2e/doppelganger/doppelganger.test.ts index fc17e209f779..bef957e46a0d 100644 --- a/packages/beacon-node/test/e2e/doppelganger/doppelganger.test.ts +++ b/packages/beacon-node/test/e2e/doppelganger/doppelganger.test.ts @@ -46,7 +46,7 @@ describe.skip("doppelganger / doppelganger test", function () { }; async function createBNAndVC(config?: TestConfig): Promise<{beaconNode: BeaconNode; validators: Validator[]}> { - const testLoggerOpts: TestLoggerOpts = {logLevel: LogLevel.info}; + const testLoggerOpts: TestLoggerOpts = {level: LogLevel.info}; const loggerNodeA = testLogger("Node-A", testLoggerOpts); const bn = await getDevBeaconNode({ @@ -150,7 +150,7 @@ describe.skip("doppelganger / doppelganger test", function () { this.timeout("10 min"); const doppelgangerProtectionEnabled = true; - const testLoggerOpts: TestLoggerOpts = {logLevel: LogLevel.info}; + const testLoggerOpts: TestLoggerOpts = {level: LogLevel.info}; // set genesis time to allow at least an epoch const genesisTime = Math.floor(Date.now() / 1000) - SLOTS_PER_EPOCH * beaconParams.SECONDS_PER_SLOT; diff --git a/packages/beacon-node/test/sim/merge-interop.test.ts b/packages/beacon-node/test/sim/merge-interop.test.ts index 7cbe493c909e..5e079e204a9f 100644 --- a/packages/beacon-node/test/sim/merge-interop.test.ts +++ b/packages/beacon-node/test/sim/merge-interop.test.ts @@ -2,7 +2,8 @@ import fs from "node:fs"; import {Context} from "mocha"; import {fromHexString} from "@chainsafe/ssz"; import {isExecutionStateType, isMergeTransitionComplete} from "@lodestar/state-transition"; -import {LogLevel, sleep, TimestampFormatCode} from "@lodestar/utils"; +import {LogLevel, sleep} from "@lodestar/utils"; +import {TimestampFormatCode} from "@lodestar/logger"; import {ForkName, SLOTS_PER_EPOCH} from "@lodestar/params"; import {ChainConfig} from "@lodestar/config"; import {routes} from "@lodestar/api"; @@ -265,8 +266,11 @@ describe("executionEngine / ExecutionEngineHttp", function () { const genesisTime = Math.floor(Date.now() / 1000) + genesisSlotsDelay * testParams.SECONDS_PER_SLOT; const testLoggerOpts: TestLoggerOpts = { - logLevel: LogLevel.info, - logFile: `${logFilesDir}/merge-interop-${testName}.log`, + level: LogLevel.info, + file: { + filepath: `${logFilesDir}/merge-interop-${testName}.log`, + level: LogLevel.debug, + }, timestampFormat: { format: TimestampFormatCode.EpochSlot, genesisTime, diff --git a/packages/beacon-node/test/sim/mergemock.test.ts b/packages/beacon-node/test/sim/mergemock.test.ts index 82ac9a236d78..d2dc37f893f5 100644 --- a/packages/beacon-node/test/sim/mergemock.test.ts +++ b/packages/beacon-node/test/sim/mergemock.test.ts @@ -1,7 +1,8 @@ import fs from "node:fs"; import {Context} from "mocha"; import {fromHexString, toHexString} from "@chainsafe/ssz"; -import {LogLevel, sleep, TimestampFormatCode} from "@lodestar/utils"; +import {LogLevel, sleep} from "@lodestar/utils"; +import {TimestampFormatCode} from "@lodestar/logger"; import {SLOTS_PER_EPOCH} from "@lodestar/params"; import {ChainConfig} from "@lodestar/config"; import {Epoch, bellatrix} from "@lodestar/types"; @@ -123,8 +124,11 @@ describe("executionEngine / ExecutionEngineHttp", function () { const genesisTime = Math.floor(Date.now() / 1000) + genesisSlotsDelay * testParams.SECONDS_PER_SLOT; const testLoggerOpts: TestLoggerOpts = { - logLevel: LogLevel.info, - logFile: `${logFilesDir}/mergemock-${testName}.log`, + level: LogLevel.info, + file: { + filepath: `${logFilesDir}/mergemock-${testName}.log`, + level: LogLevel.debug, + }, timestampFormat: { format: TimestampFormatCode.EpochSlot, genesisTime, diff --git a/packages/beacon-node/test/sim/withdrawal-interop.test.ts b/packages/beacon-node/test/sim/withdrawal-interop.test.ts index 3634c561d67f..e347adeceea3 100644 --- a/packages/beacon-node/test/sim/withdrawal-interop.test.ts +++ b/packages/beacon-node/test/sim/withdrawal-interop.test.ts @@ -1,7 +1,8 @@ import fs from "node:fs"; import {Context} from "mocha"; import {fromHexString, toHexString} from "@chainsafe/ssz"; -import {LogLevel, sleep, TimestampFormatCode} from "@lodestar/utils"; +import {LogLevel, sleep} from "@lodestar/utils"; +import {TimestampFormatCode} from "@lodestar/logger"; import {SLOTS_PER_EPOCH, ForkName} from "@lodestar/params"; import {ChainConfig} from "@lodestar/config"; import {computeStartSlotAtEpoch} from "@lodestar/state-transition"; @@ -233,8 +234,11 @@ describe("executionEngine / ExecutionEngineHttp", function () { const genesisTime = Math.floor(Date.now() / 1000) + genesisSlotsDelay * testParams.SECONDS_PER_SLOT; const testLoggerOpts: TestLoggerOpts = { - logLevel: LogLevel.info, - logFile: `${logFilesDir}/mergemock-${testName}.log`, + level: LogLevel.info, + file: { + filepath: `${logFilesDir}/mergemock-${testName}.log`, + level: LogLevel.debug, + }, timestampFormat: { format: TimestampFormatCode.EpochSlot, genesisTime, diff --git a/packages/beacon-node/test/unit/chain/prepareNextSlot.test.ts b/packages/beacon-node/test/unit/chain/prepareNextSlot.test.ts index 74b2a142259d..1d36fa43040f 100644 --- a/packages/beacon-node/test/unit/chain/prepareNextSlot.test.ts +++ b/packages/beacon-node/test/unit/chain/prepareNextSlot.test.ts @@ -2,10 +2,10 @@ import {expect} from "chai"; import sinon, {SinonStubbedInstance} from "sinon"; import {config} from "@lodestar/config/default"; import {ForkChoice, ProtoBlock} from "@lodestar/fork-choice"; -import {WinstonLogger} from "@lodestar/utils"; import {ForkName, SLOTS_PER_EPOCH} from "@lodestar/params"; import {ChainForkConfig} from "@lodestar/config"; import {routes} from "@lodestar/api"; +import {LoggerNode} from "@lodestar/logger/node"; import {BeaconChain, ChainEventEmitter} from "../../../src/chain/index.js"; import {IBeaconChain} from "../../../src/chain/interface.js"; import {IChainOptions} from "../../../src/chain/options.js"; @@ -20,6 +20,7 @@ import {ExecutionEngineHttp} from "../../../src/execution/engine/http.js"; import {IExecutionEngine} from "../../../src/execution/engine/interface.js"; import {StubbedChainMutable} from "../../utils/stub/index.js"; import {zeroProtoBlock} from "../../utils/mocks/chain/chain.js"; +import {createStubbedLogger} from "../../utils/mocks/logger.js"; type StubbedChain = StubbedChainMutable<"clock" | "forkChoice" | "emitter" | "regen" | "opts">; @@ -31,7 +32,7 @@ describe("PrepareNextSlot scheduler", () => { let scheduler: PrepareNextSlotScheduler; let forkChoiceStub: SinonStubbedInstance & ForkChoice; let regenStub: SinonStubbedInstance & StateRegenerator; - let loggerStub: SinonStubbedInstance & WinstonLogger; + let loggerStub: SinonStubbedInstance & LoggerNode; let beaconProposerCacheStub: SinonStubbedInstance & BeaconProposerCache; let getForkStub: SinonStubFn<(typeof config)["getForkName"]>; let updateBuilderStatus: SinonStubFn; @@ -51,7 +52,7 @@ describe("PrepareNextSlot scheduler", () => { regenStub = sandbox.createStubInstance(StateRegenerator) as SinonStubbedInstance & StateRegenerator; chainStub.regen = regenStub; - loggerStub = sandbox.createStubInstance(WinstonLogger) as SinonStubbedInstance & WinstonLogger; + loggerStub = createStubbedLogger(sandbox); beaconProposerCacheStub = sandbox.createStubInstance( BeaconProposerCache ) as SinonStubbedInstance & BeaconProposerCache; diff --git a/packages/beacon-node/test/utils/logger.ts b/packages/beacon-node/test/utils/logger.ts index c068d1ba9a6b..b3382cc221e2 100644 --- a/packages/beacon-node/test/utils/logger.ts +++ b/packages/beacon-node/test/utils/logger.ts @@ -1,12 +1,9 @@ -import winston from "winston"; -import {createWinstonLogger, Logger, LogLevel, TimestampFormat} from "@lodestar/utils"; +import {LogLevel} from "@lodestar/utils"; +import {getNodeLogger, LoggerNode, LoggerNodeOpts} from "@lodestar/logger/node"; +import {getEnvLogLevel} from "@lodestar/logger/env"; export {LogLevel}; -export type TestLoggerOpts = { - logLevel?: LogLevel; - logFile?: string; - timestampFormat?: TimestampFormat; -}; +export type TestLoggerOpts = LoggerNodeOpts; /** * Run the test with ENVs to control log level: @@ -16,25 +13,14 @@ export type TestLoggerOpts = { * VERBOSE=1 mocha .ts * ``` */ -export function testLogger(module?: string, opts?: TestLoggerOpts): Logger { - const transports: winston.transport[] = [ - new winston.transports.Console({level: getLogLevelFromEnvs() || opts?.logLevel || LogLevel.error}), - ]; - if (opts?.logFile) { - transports.push( - new winston.transports.File({ - level: LogLevel.debug, - filename: opts.logFile, - }) - ); +export const testLogger = (module?: string, opts?: TestLoggerOpts): LoggerNode => { + if (opts == null) { + opts = {} as LoggerNodeOpts; } - - return createWinstonLogger({module, ...opts}, transports); -} - -function getLogLevelFromEnvs(): LogLevel | null { - if (process.env["LOG_LEVEL"]) return process.env["LOG_LEVEL"] as LogLevel; - if (process.env["DEBUG"]) return LogLevel.debug; - if (process.env["VERBOSE"]) return LogLevel.verbose; - return null; -} + if (module) { + opts.module = module; + } + const level = getEnvLogLevel(); + opts.level = level ?? LogLevel.info; + return getNodeLogger(opts); +}; diff --git a/packages/beacon-node/test/utils/mocks/logger.ts b/packages/beacon-node/test/utils/mocks/logger.ts index 86eadf629b4c..d827805fa648 100644 --- a/packages/beacon-node/test/utils/mocks/logger.ts +++ b/packages/beacon-node/test/utils/mocks/logger.ts @@ -1,11 +1,15 @@ -import sinon from "sinon"; -import {Logger} from "@lodestar/utils"; +import sinon, {SinonSandbox, SinonStubbedInstance} from "sinon"; +import {LoggerNode} from "@lodestar/logger/node"; -export const createStubbedLogger = (): Logger => ({ - debug: sinon.stub(), - info: sinon.stub(), - error: sinon.stub(), - warn: sinon.stub(), - verbose: sinon.stub(), - child: sinon.stub(), -}); +export const createStubbedLogger = (sandbox?: SinonSandbox): LoggerNode & SinonStubbedInstance => { + sandbox = sandbox ?? sinon; + return { + debug: sandbox.stub(), + info: sandbox.stub(), + error: sandbox.stub(), + warn: sandbox.stub(), + verbose: sandbox.stub(), + child: sandbox.stub(), + toOpts: sandbox.stub(), + } as unknown as LoggerNode & SinonStubbedInstance; +}; diff --git a/packages/beacon-node/test/utils/node/beacon.ts b/packages/beacon-node/test/utils/node/beacon.ts index d948bc571b75..9f871a3101db 100644 --- a/packages/beacon-node/test/utils/node/beacon.ts +++ b/packages/beacon-node/test/utils/node/beacon.ts @@ -4,12 +4,13 @@ import {PeerId} from "@libp2p/interface-peer-id"; import {createSecp256k1PeerId} from "@libp2p/peer-id-factory"; import {config as minimalConfig} from "@lodestar/config/default"; import {createBeaconConfig, createChainForkConfig, ChainConfig} from "@lodestar/config"; -import {Logger, RecursivePartial} from "@lodestar/utils"; +import {RecursivePartial} from "@lodestar/utils"; import {LevelDbController} from "@lodestar/db"; import {phase0, ssz} from "@lodestar/types"; import {ForkSeq, GENESIS_SLOT} from "@lodestar/params"; import {BeaconStateAllForks} from "@lodestar/state-transition"; import {isPlainObject} from "@lodestar/utils"; +import {LoggerNode} from "@lodestar/logger/node"; import {BeaconNode} from "../../../src/index.js"; import {defaultNetworkOptions} from "../../../src/network/options.js"; import {initDevState, writeDeposits} from "../../../src/node/utils/state.js"; @@ -24,7 +25,7 @@ export async function getDevBeaconNode( params: Partial; options?: RecursivePartial; validatorCount?: number; - logger?: Logger; + logger?: LoggerNode; peerId?: PeerId; peerStoreDir?: string; anchorState?: BeaconStateAllForks; diff --git a/packages/cli/package.json b/packages/cli/package.json index fbc875c232a4..0617c8aef5d2 100644 --- a/packages/cli/package.json +++ b/packages/cli/package.json @@ -66,6 +66,7 @@ "@lodestar/config": "^1.8.0", "@lodestar/db": "^1.8.0", "@lodestar/light-client": "^1.8.0", + "@lodestar/logger": "^1.8.0", "@lodestar/params": "^1.8.0", "@lodestar/state-transition": "^1.8.0", "@lodestar/types": "^1.8.0", diff --git a/packages/cli/src/cmds/beacon/handler.ts b/packages/cli/src/cmds/beacon/handler.ts index 1a86c3ed8d04..eedc5d3a334d 100644 --- a/packages/cli/src/cmds/beacon/handler.ts +++ b/packages/cli/src/cmds/beacon/handler.ts @@ -1,16 +1,17 @@ import path from "node:path"; import {Registry} from "prom-client"; -import {ErrorAborted, Logger} from "@lodestar/utils"; +import {ErrorAborted} from "@lodestar/utils"; import {LevelDbController} from "@lodestar/db"; import {BeaconNode, BeaconDb} from "@lodestar/beacon-node"; import {ChainForkConfig, createBeaconConfig} from "@lodestar/config"; import {ACTIVE_PRESET, PresetName} from "@lodestar/params"; import {ProcessShutdownCallback} from "@lodestar/validator"; +import {LoggerNode, getNodeLogger} from "@lodestar/logger/node"; import {GlobalArgs, parseBeaconNodeArgs} from "../../options/index.js"; import {BeaconNodeOptions, getBeaconConfigFromArgs} from "../../config/index.js"; import {getNetworkBootnodes, getNetworkData, isKnownNetworkName, readBootnodes} from "../../networks/index.js"; -import {onGracefulShutdown, getCliLogger, mkdir, writeFile600Perm, cleanOldLogFiles} from "../../util/index.js"; +import {onGracefulShutdown, mkdir, writeFile600Perm, cleanOldLogFiles, parseLoggerArgs} from "../../util/index.js"; import {getVersionData} from "../../util/version.js"; import {BeaconArgs} from "./options.js"; import {getBeaconPaths} from "./paths.js"; @@ -149,12 +150,13 @@ export async function beaconHandlerInit(args: BeaconArgs & GlobalArgs) { return {config, options, beaconPaths, network, version, commit, peerId, logger}; } -export function initLogger(args: BeaconArgs, dataDir: string, config: ChainForkConfig): Logger { - const {logger, logParams} = getCliLogger(args, {defaultLogFilepath: path.join(dataDir, "beacon.log")}, config); +export function initLogger(args: BeaconArgs, dataDir: string, config: ChainForkConfig): LoggerNode { + const defaultLogFilepath = path.join(dataDir, "beacon.log"); + const logger = getNodeLogger(parseLoggerArgs(args, {defaultLogFilepath}, config)); try { - cleanOldLogFiles(logParams.filename, logParams.rotateMaxFiles); + cleanOldLogFiles(args, {defaultLogFilepath}); } catch (e) { - logger.debug("Not able to delete log files", logParams, e as Error); + logger.debug("Not able to delete log files", {}, e as Error); } return logger; diff --git a/packages/cli/src/cmds/beacon/options.ts b/packages/cli/src/cmds/beacon/options.ts index d8915474fd21..52f4d5437f27 100644 --- a/packages/cli/src/cmds/beacon/options.ts +++ b/packages/cli/src/cmds/beacon/options.ts @@ -1,7 +1,7 @@ import {Options} from "yargs"; import {beaconNodeOptions, paramsOptions, BeaconNodeArgs} from "../../options/index.js"; -import {logOptions} from "../../options/logOptions.js"; -import {CliCommandOptions, LogArgs} from "../../util/index.js"; +import {LogArgs, logOptions} from "../../options/logOptions.js"; +import {CliCommandOptions} from "../../util/index.js"; import {defaultBeaconPaths, BeaconPaths} from "./paths.js"; type BeaconExtraArgs = { diff --git a/packages/cli/src/cmds/lightclient/handler.ts b/packages/cli/src/cmds/lightclient/handler.ts index 2fc35df931bd..11e5ed743d54 100644 --- a/packages/cli/src/cmds/lightclient/handler.ts +++ b/packages/cli/src/cmds/lightclient/handler.ts @@ -3,17 +3,20 @@ import {ApiError, getClient} from "@lodestar/api"; import {Lightclient} from "@lodestar/light-client"; import {fromHexString} from "@chainsafe/ssz"; import {LightClientRestTransport} from "@lodestar/light-client/transport"; +import {getNodeLogger} from "@lodestar/logger/node"; import {getBeaconConfigFromArgs} from "../../config/beaconParams.js"; import {getGlobalPaths} from "../../paths/global.js"; +import {parseLoggerArgs} from "../../util/logger.js"; import {GlobalArgs} from "../../options/index.js"; -import {getCliLogger} from "../../util/index.js"; import {ILightClientArgs} from "./options.js"; export async function lightclientHandler(args: ILightClientArgs & GlobalArgs): Promise { const {config, network} = getBeaconConfigFromArgs(args); const globalPaths = getGlobalPaths(args, network); - const {logger} = getCliLogger(args, {defaultLogFilepath: path.join(globalPaths.dataDir, "lightclient.log")}, config); + const logger = getNodeLogger( + parseLoggerArgs(args, {defaultLogFilepath: path.join(globalPaths.dataDir, "lightclient.log")}, config) + ); const {beaconApiUrl, checkpointRoot} = args; const api = getClient({baseUrl: beaconApiUrl}, {config}); const res = await api.beacon.getGenesis(); diff --git a/packages/cli/src/cmds/lightclient/options.ts b/packages/cli/src/cmds/lightclient/options.ts index bef8cc724906..ba68a7aa5a5c 100644 --- a/packages/cli/src/cmds/lightclient/options.ts +++ b/packages/cli/src/cmds/lightclient/options.ts @@ -1,5 +1,5 @@ -import {logOptions} from "../../options/logOptions.js"; -import {CliCommandOptions, LogArgs} from "../../util/index.js"; +import {LogArgs, logOptions} from "../../options/logOptions.js"; +import {CliCommandOptions} from "../../util/index.js"; export type ILightClientArgs = LogArgs & { beaconApiUrl: string; diff --git a/packages/cli/src/cmds/validator/handler.ts b/packages/cli/src/cmds/validator/handler.ts index 81fe7aaec699..4b09afc687fe 100644 --- a/packages/cli/src/cmds/validator/handler.ts +++ b/packages/cli/src/cmds/validator/handler.ts @@ -10,9 +10,10 @@ import { } from "@lodestar/validator"; import {getMetrics, MetricsRegister} from "@lodestar/validator"; import {RegistryMetricCreator, collectNodeJSMetrics, HttpMetricsServer, MonitoringService} from "@lodestar/beacon-node"; +import {getNodeLogger} from "@lodestar/logger/node"; import {getBeaconConfigFromArgs} from "../../config/index.js"; import {GlobalArgs} from "../../options/index.js"; -import {YargsError, getDefaultGraffiti, mkdir, getCliLogger, cleanOldLogFiles} from "../../util/index.js"; +import {YargsError, cleanOldLogFiles, getDefaultGraffiti, mkdir, parseLoggerArgs} from "../../util/index.js"; import {onGracefulShutdown, parseFeeRecipient, parseProposerConfig} from "../../util/index.js"; import {getVersionData} from "../../util/version.js"; import {getAccountPaths, getValidatorPaths} from "./paths.js"; @@ -35,15 +36,12 @@ export async function validatorHandler(args: IValidatorCliArgs & GlobalArgs): Pr const validatorPaths = getValidatorPaths(args, network); const accountPaths = getAccountPaths(args, network); - const {logger, logParams} = getCliLogger( - args, - {defaultLogFilepath: path.join(validatorPaths.dataDir, "validator.log")}, - config - ); + const defaultLogFilepath = path.join(validatorPaths.dataDir, "validator.log"); + const logger = getNodeLogger(parseLoggerArgs(args, {defaultLogFilepath}, config)); try { - cleanOldLogFiles(logParams.filename, logParams.rotateMaxFiles); + cleanOldLogFiles(args, {defaultLogFilepath}); } catch (e) { - logger.debug("Not able to delete log files", logParams, e as Error); + logger.debug("Not able to delete log files", {}, e as Error); } const persistedKeysBackend = new PersistedKeysBackend(accountPaths); diff --git a/packages/cli/src/cmds/validator/keymanager/decryptKeystoreDefinitions/types.ts b/packages/cli/src/cmds/validator/keymanager/decryptKeystoreDefinitions/types.ts index 863d31acab6c..9ebe9b83a878 100644 --- a/packages/cli/src/cmds/validator/keymanager/decryptKeystoreDefinitions/types.ts +++ b/packages/cli/src/cmds/validator/keymanager/decryptKeystoreDefinitions/types.ts @@ -1,4 +1,4 @@ -import {Logger} from "@lodestar/utils"; +import {LogLevel, Logger} from "@lodestar/utils"; import {LocalKeystoreDefinition} from "../interface.js"; export type DecryptKeystoreWorkerAPI = { @@ -10,5 +10,5 @@ export type KeystoreDecryptOptions = { onDecrypt?: (index: number) => void; // Try to use the cache file if it exists cacheFilePath?: string; - logger: Pick; + logger: Pick; }; diff --git a/packages/cli/src/cmds/validator/options.ts b/packages/cli/src/cmds/validator/options.ts index b1eeef860d44..a631d3134ed2 100644 --- a/packages/cli/src/cmds/validator/options.ts +++ b/packages/cli/src/cmds/validator/options.ts @@ -1,6 +1,6 @@ import {defaultOptions} from "@lodestar/validator"; -import {logOptions} from "../../options/logOptions.js"; -import {ensure0xPrefix, CliCommandOptions, LogArgs} from "../../util/index.js"; +import {LogArgs, logOptions} from "../../options/logOptions.js"; +import {ensure0xPrefix, CliCommandOptions} from "../../util/index.js"; import {keymanagerRestApiServerOptsDefault} from "./keymanager/server.js"; import {defaultAccountPaths, defaultValidatorPaths} from "./paths.js"; diff --git a/packages/cli/src/cmds/validator/signers/index.ts b/packages/cli/src/cmds/validator/signers/index.ts index 0b94e34e848c..fb8f2aedbf9b 100644 --- a/packages/cli/src/cmds/validator/signers/index.ts +++ b/packages/cli/src/cmds/validator/signers/index.ts @@ -4,7 +4,7 @@ import {deriveEth2ValidatorKeys, deriveKeyFromMnemonic} from "@chainsafe/bls-key import {interopSecretKey} from "@lodestar/state-transition"; import {externalSignerGetKeys, Signer, SignerType} from "@lodestar/validator"; import {toHexString} from "@chainsafe/ssz"; -import {Logger} from "@lodestar/utils"; +import {LogLevel, Logger} from "@lodestar/utils"; import {defaultNetwork, GlobalArgs} from "../../../options/index.js"; import {assertValidPubkeysHex, isValidHttpUrl, parseRange, YargsError} from "../../../util/index.js"; import {getAccountPaths} from "../paths.js"; @@ -44,7 +44,7 @@ const KEYSTORE_IMPORT_PROGRESS_MS = 10000; export async function getSignersFromArgs( args: IValidatorCliArgs & GlobalArgs, network: string, - {logger, signal}: {logger: Pick; signal: AbortSignal} + {logger, signal}: {logger: Pick; signal: AbortSignal} ): Promise { const accountPaths = getAccountPaths(args, network); diff --git a/packages/cli/src/cmds/validator/signers/logSigners.ts b/packages/cli/src/cmds/validator/signers/logSigners.ts index 0712b18d4125..85d17ad323ae 100644 --- a/packages/cli/src/cmds/validator/signers/logSigners.ts +++ b/packages/cli/src/cmds/validator/signers/logSigners.ts @@ -1,10 +1,10 @@ import {Signer, SignerLocal, SignerRemote, SignerType} from "@lodestar/validator"; -import {Logger} from "@lodestar/utils"; +import {LogLevel, Logger} from "@lodestar/utils"; /** * Log each pubkeys for auditing out keys are loaded from the logs */ -export function logSigners(logger: Pick, signers: Signer[]): void { +export function logSigners(logger: Pick, signers: Signer[]): void { const localSigners: SignerLocal[] = []; const remoteSigners: SignerRemote[] = []; diff --git a/packages/cli/src/cmds/validator/slashingProtection/export.ts b/packages/cli/src/cmds/validator/slashingProtection/export.ts index d745715fc027..3557aa6ee456 100644 --- a/packages/cli/src/cmds/validator/slashingProtection/export.ts +++ b/packages/cli/src/cmds/validator/slashingProtection/export.ts @@ -1,10 +1,12 @@ import path from "node:path"; import {toHexString} from "@chainsafe/ssz"; import {InterchangeFormatVersion} from "@lodestar/validator"; +import {getNodeLogger} from "@lodestar/logger/node"; import {CliCommand, YargsError, ensure0xPrefix, isValidatePubkeyHex, writeFile600Perm} from "../../../util/index.js"; +import {parseLoggerArgs} from "../../../util/logger.js"; import {GlobalArgs} from "../../../options/index.js"; +import {LogArgs} from "../../../options/logOptions.js"; import {AccountValidatorArgs} from "../options.js"; -import {getCliLogger, LogArgs} from "../../../util/index.js"; import {getBeaconConfigFromArgs} from "../../../config/index.js"; import {getValidatorPaths} from "../paths.js"; import {getGenesisValidatorsRoot, getSlashingProtection} from "./utils.js"; @@ -51,10 +53,8 @@ export const exportCmd: CliCommand = { logLevel: { choices: LogLevels, description: "Logging verbosity level for emittings logs to terminal", - default: LOG_LEVEL_DEFAULT, + default: LogLevel.info, type: "string", }, @@ -24,14 +30,14 @@ export const logOptions: CliCommandOptions = { logFileLevel: { choices: LogLevels, description: "Logging verbosity level for emittings logs to file", - default: LOG_FILE_LEVEL_DEFAULT, + default: LogLevel.debug, type: "string", }, logFileDailyRotate: { description: "Daily rotate log files, set to an integer to limit the file count, set to 0(zero) to disable rotation", - default: LOG_DAILY_ROTATE_DEFAULT, + default: 5, type: "number", }, diff --git a/packages/cli/src/util/logger.ts b/packages/cli/src/util/logger.ts index 9dac44e3782d..ada5e79bb3dd 100644 --- a/packages/cli/src/util/logger.ts +++ b/packages/cli/src/util/logger.ts @@ -1,103 +1,40 @@ import path from "node:path"; import fs from "node:fs"; -import DailyRotateFile from "winston-daily-rotate-file"; -import TransportStream from "winston-transport"; -import winston from "winston"; import {ChainForkConfig} from "@lodestar/config"; import {SLOTS_PER_EPOCH} from "@lodestar/params"; -import { - Logger, - LogLevel, - createWinstonLogger, - TimestampFormat, - TimestampFormatCode, - LogFormat, - logFormats, -} from "@lodestar/utils"; +import {LogFormat, TimestampFormatCode, logFormats} from "@lodestar/logger"; +import {LoggerNodeOpts} from "@lodestar/logger/node"; +import {LogLevel} from "@lodestar/utils"; +import {LogArgs} from "../options/logOptions.js"; import {GlobalArgs} from "../options/globalOptions.js"; -import {ConsoleDynamicLevel} from "./loggerConsoleTransport.js"; export const LOG_FILE_DISABLE_KEYWORD = "none"; -export const LOG_LEVEL_DEFAULT = LogLevel.info; -export const LOG_FILE_LEVEL_DEFAULT = LogLevel.debug; -export const LOG_DAILY_ROTATE_DEFAULT = 5; -const DATE_PATTERN = "YYYY-MM-DD"; - -export type LogArgs = { - logLevel?: LogLevel; - logFile?: string; - logFileLevel?: LogLevel; - logFileDailyRotate?: number; - logFormatGenesisTime?: number; - logPrefix?: string; - logFormat?: string; - logLevelModule?: string[]; -}; /** * Setup a CLI logger, common for beacon, validator and dev commands */ -export function getCliLogger( +export function parseLoggerArgs( args: LogArgs & Pick, paths: {defaultLogFilepath: string}, config: ChainForkConfig, opts?: {hideTimestamp?: boolean} -): {logger: Logger; logParams: {filename: string; rotateMaxFiles: number}} { - const consoleTransport = new ConsoleDynamicLevel({ - // Set defaultLevel, not level for dynamic level setting of ConsoleDynamicLvevel - defaultLevel: args.logLevel ?? LOG_LEVEL_DEFAULT, - debugStdout: true, - handleExceptions: true, - }); - - if (args.logLevelModule) { - for (const logLevelModule of args.logLevelModule ?? []) { - const [module, levelStr] = logLevelModule.split("="); - const level = levelStr as LogLevel; - if (LogLevel[level as LogLevel] === undefined) { - throw Error(`Unknown level in logLevelModule '${logLevelModule}'`); - } - - consoleTransport.setModuleLevel(module, level); - } - } - - const transports: TransportStream[] = [consoleTransport]; - - // yargs populates with undefined if just set but with no arg - // $ ./bin/lodestar.js beacon --logFileDailyRotate - // args = { - // logFileDailyRotate: undefined, - // } - // `lodestar --logFileDailyRotate` -> enabled daily rotate with default value - // `lodestar --logFileDailyRotate 10` -> set daily rotate to custom value 10 - // `lodestar --logFileDailyRotate 0` -> disable daily rotate and accumulate in same file - const rotateMaxFiles = args.logFileDailyRotate ?? LOG_DAILY_ROTATE_DEFAULT; - const filename = args.logFile ?? paths.defaultLogFilepath; - if (args.logFile !== LOG_FILE_DISABLE_KEYWORD) { - const logFileLevel = args.logFileLevel ?? LOG_FILE_LEVEL_DEFAULT; - - transports.push( - rotateMaxFiles > 0 - ? new DailyRotateFile({ - level: logFileLevel, - //insert the date pattern in filename before the file extension. - filename: filename.replace(/\.(?=[^.]*$)|$/, "-%DATE%$&"), - datePattern: DATE_PATTERN, - handleExceptions: true, - maxFiles: rotateMaxFiles, - auditFile: path.join(path.dirname(filename), ".log_rotate_audit.json"), - }) - : new winston.transports.File({ - level: logFileLevel, - filename: filename, - handleExceptions: true, - }) - ); - } - - const timestampFormat: TimestampFormat = - args.logFormatGenesisTime !== undefined +): LoggerNodeOpts { + return { + level: parseLogLevel(args.logLevel), + file: + args.logFile === LOG_FILE_DISABLE_KEYWORD + ? undefined + : { + filepath: args.logFile ?? paths.defaultLogFilepath, + level: parseLogLevel(args.logFileLevel), + dailyRotate: args.logFileDailyRotate, + }, + module: args.logPrefix, + format: args.logFormat ? parseLogFormat(args.logFormat) : undefined, + levelModule: args.logLevelModule && parseLogLevelModule(args.logLevelModule), + timestampFormat: opts?.hideTimestamp + ? {format: TimestampFormatCode.Hidden} + : args.logFormatGenesisTime !== undefined ? { format: TimestampFormatCode.EpochSlot, genesisTime: args.logFormatGenesisTime, @@ -106,19 +43,31 @@ export function getCliLogger( } : { format: TimestampFormatCode.DateRegular, - }; + }, + }; +} + +function parseLogFormat(format: string): LogFormat { + if (!logFormats.includes(format as LogFormat)) { + throw Error(`Unknown log format ${format}`); + } + return format as LogFormat; +} - const logger = createWinstonLogger( - { - module: args.logPrefix, - format: args.logFormat ? parseLogFormat(args.logFormat) : "human", - timestampFormat, - hideTimestamp: opts?.hideTimestamp, - }, - transports - ); +function parseLogLevel(level: string): LogLevel { + if (LogLevel[level as LogLevel] === undefined) { + throw Error(`Unknown log level '${level}'`); + } + return level as LogLevel; +} - return {logger, logParams: {filename, rotateMaxFiles}}; +function parseLogLevelModule(logLevelModuleArr: string[]): Record { + const levelModule: Record = {}; + for (const logLevelModule of logLevelModuleArr) { + const [module, levelStr] = logLevelModule.split("="); + levelModule[module] = parseLogLevel(levelStr); + } + return levelModule; } /** @@ -126,9 +75,10 @@ export function getCliLogger( * so we have to do this manually when starting the node. * See https://github.com/ChainSafe/lodestar/issues/4419 */ -export function cleanOldLogFiles(filePath: string, maxFiles: number): void { - const folder = path.dirname(filePath); - const filename = path.basename(filePath); +export function cleanOldLogFiles(args: LogArgs, paths: {defaultLogFilepath: string}): void { + const filepath = args.logFile ?? paths.defaultLogFilepath; + const folder = path.dirname(filepath); + const filename = path.basename(filepath); const lastIndexDot = filename.lastIndexOf("."); const prefix = filename.substring(0, lastIndexDot); const extension = filename.substring(lastIndexDot + 1, filename.length); @@ -136,7 +86,7 @@ export function cleanOldLogFiles(filePath: string, maxFiles: number): void { .readdirSync(folder, {withFileTypes: true}) .filter((de) => de.isFile()) .map((de) => de.name) - .filter((logFileName) => shouldDeleteLogFile(prefix, extension, logFileName, maxFiles)) + .filter((logFileName) => shouldDeleteLogFile(prefix, extension, logFileName, args.logFileDailyRotate)) .map((logFileName) => path.join(folder, logFileName)); // delete files toDelete.forEach((filename) => fs.unlinkSync(filename)); @@ -151,11 +101,3 @@ export function shouldDeleteLogFile(prefix: string, extension: string, logFileNa } return false; } - -function parseLogFormat(format: string): LogFormat { - if (!logFormats.includes(format as LogFormat)) { - throw Error(`Invalid log format '${format}'`); - } - - return format as LogFormat; -} diff --git a/packages/cli/test/unit/cmds/beacon.test.ts b/packages/cli/test/unit/cmds/beacon.test.ts index a7d8d67b2a02..8891e3f8d3a8 100644 --- a/packages/cli/test/unit/cmds/beacon.test.ts +++ b/packages/cli/test/unit/cmds/beacon.test.ts @@ -6,6 +6,7 @@ import {multiaddr} from "@multiformats/multiaddr"; import {chainConfig} from "@lodestar/config/default"; import {chainConfigToJson} from "@lodestar/config"; import {createKeypairFromPeerId, ENR, SignableENR} from "@chainsafe/discv5"; +import {LogLevel} from "@lodestar/utils"; import {exportToJSON} from "../../../src/config/peerId.js"; import {beaconHandlerInit} from "../../../src/cmds/beacon/handler.js"; import {initPeerIdAndEnr, isLocalMultiAddr} from "../../../src/cmds/beacon/initPeerIdAndEnr.js"; @@ -184,6 +185,8 @@ describe("initPeerIdAndEnr", () => { // eslint-disable-next-line @typescript-eslint/explicit-function-return-type async function runBeaconHandlerInit(args: Partial) { return beaconHandlerInit({ + logLevel: LogLevel.info, + logFileLevel: LogLevel.debug, dataDir: testFilesDir, ...args, } as BeaconArgs & GlobalArgs); diff --git a/packages/cli/test/utils.ts b/packages/cli/test/utils.ts index 991aabe958ec..51fd5f3742b2 100644 --- a/packages/cli/test/utils.ts +++ b/packages/cli/test/utils.ts @@ -1,14 +1,36 @@ import fs from "node:fs"; import path from "node:path"; import tmp from "tmp"; -import {createWinstonLogger, Logger} from "@lodestar/utils"; +import {getEnvLogLevel} from "@lodestar/logger/env"; +import {LoggerNode, LoggerNodeOpts, getNodeLogger} from "@lodestar/logger/node"; +import {LogLevel} from "@lodestar/utils"; export const networkDev = "dev"; const tmpDir = tmp.dirSync({unsafeCleanup: true}); export const testFilesDir = tmpDir.name; -export const testLogger = (): Logger => createWinstonLogger(); +export type TestLoggerOpts = LoggerNodeOpts; + +/** + * Run the test with ENVs to control log level: + * ``` + * LOG_LEVEL=debug mocha .ts + * DEBUG=1 mocha .ts + * VERBOSE=1 mocha .ts + * ``` + */ +export const testLogger = (module?: string, opts?: TestLoggerOpts): LoggerNode => { + if (opts == null) { + opts = {} as LoggerNodeOpts; + } + if (module) { + opts.module = module; + } + const level = getEnvLogLevel(); + opts.level = level ?? LogLevel.info; + return getNodeLogger(opts); +}; export function getTestdirPath(filepath: string): string { const fullpath = path.join(testFilesDir, filepath); diff --git a/packages/db/package.json b/packages/db/package.json index 635ae19dab35..4da895ad7fa3 100644 --- a/packages/db/package.json +++ b/packages/db/package.json @@ -44,5 +44,8 @@ "@types/levelup": "^4.3.3", "it-all": "^3.0.1", "level": "^8.0.0" + }, + "devDependencies": { + "@lodestar/logger": "^1.8.0" } } diff --git a/packages/db/test/unit/controller/level.test.ts b/packages/db/test/unit/controller/level.test.ts index 89abffe67d5f..d0a23919d8cf 100644 --- a/packages/db/test/unit/controller/level.test.ts +++ b/packages/db/test/unit/controller/level.test.ts @@ -2,12 +2,12 @@ import {execSync} from "node:child_process"; import {expect} from "chai"; import leveldown from "leveldown"; import all from "it-all"; +import {getEnvLogger} from "@lodestar/logger/env"; import {LevelDbController} from "../../../src/controller/index.js"; -import {testLogger} from "../../utils/logger.js"; describe("LevelDB controller", () => { const dbLocation = "./.__testdb"; - const db = new LevelDbController({name: dbLocation}, {metrics: null, logger: testLogger()}); + const db = new LevelDbController({name: dbLocation}, {metrics: null, logger: getEnvLogger()}); before(async () => { await db.start(); diff --git a/packages/db/test/utils/logger.ts b/packages/db/test/utils/logger.ts deleted file mode 100644 index d3f6e0f48e2d..000000000000 --- a/packages/db/test/utils/logger.ts +++ /dev/null @@ -1,20 +0,0 @@ -import {createWinstonLogger, LogLevel, Logger} from "@lodestar/utils"; - -/** - * Run the test with ENVs to control log level: - * ``` - * LOG_LEVEL=debug mocha .ts - * DEBUG=1 mocha .ts - * VERBOSE=1 mocha .ts - * ``` - */ -export function testLogger(module?: string): Logger { - return createWinstonLogger({level: getLogLevel(), module}); -} - -function getLogLevel(): LogLevel { - if (process.env["LOG_LEVEL"]) return process.env["LOG_LEVEL"] as LogLevel; - if (process.env["DEBUG"]) return LogLevel.debug; - if (process.env["VERBOSE"]) return LogLevel.verbose; - return LogLevel.error; -} diff --git a/packages/logger/.mocharc.yml b/packages/logger/.mocharc.yml new file mode 100644 index 000000000000..8b4eb53ed37a --- /dev/null +++ b/packages/logger/.mocharc.yml @@ -0,0 +1,3 @@ +colors: true +node-option: + - "loader=ts-node/esm" diff --git a/packages/logger/LICENSE b/packages/logger/LICENSE new file mode 100644 index 000000000000..f49a4e16e68b --- /dev/null +++ b/packages/logger/LICENSE @@ -0,0 +1,201 @@ + Apache License + Version 2.0, January 2004 + http://www.apache.org/licenses/ + + TERMS AND CONDITIONS FOR USE, REPRODUCTION, AND DISTRIBUTION + + 1. Definitions. + + "License" shall mean the terms and conditions for use, reproduction, + and distribution as defined by Sections 1 through 9 of this document. + + "Licensor" shall mean the copyright owner or entity authorized by + the copyright owner that is granting the License. + + "Legal Entity" shall mean the union of the acting entity and all + other entities that control, are controlled by, or are under common + control with that entity. For the purposes of this definition, + "control" means (i) the power, direct or indirect, to cause the + direction or management of such entity, whether by contract or + otherwise, or (ii) ownership of fifty percent (50%) or more of the + outstanding shares, or (iii) beneficial ownership of such entity. + + "You" (or "Your") shall mean an individual or Legal Entity + exercising permissions granted by this License. + + "Source" form shall mean the preferred form for making modifications, + including but not limited to software source code, documentation + source, and configuration files. + + "Object" form shall mean any form resulting from mechanical + transformation or translation of a Source form, including but + not limited to compiled object code, generated documentation, + and conversions to other media types. + + "Work" shall mean the work of authorship, whether in Source or + Object form, made available under the License, as indicated by a + copyright notice that is included in or attached to the work + (an example is provided in the Appendix below). + + "Derivative Works" shall mean any work, whether in Source or Object + form, that is based on (or derived from) the Work and for which the + editorial revisions, annotations, elaborations, or other modifications + represent, as a whole, an original work of authorship. For the purposes + of this License, Derivative Works shall not include works that remain + separable from, or merely link (or bind by name) to the interfaces of, + the Work and Derivative Works thereof. + + "Contribution" shall mean any work of authorship, including + the original version of the Work and any modifications or additions + to that Work or Derivative Works thereof, that is intentionally + submitted to Licensor for inclusion in the Work by the copyright owner + or by an individual or Legal Entity authorized to submit on behalf of + the copyright owner. For the purposes of this definition, "submitted" + means any form of electronic, verbal, or written communication sent + to the Licensor or its representatives, including but not limited to + communication on electronic mailing lists, source code control systems, + and issue tracking systems that are managed by, or on behalf of, the + Licensor for the purpose of discussing and improving the Work, but + excluding communication that is conspicuously marked or otherwise + designated in writing by the copyright owner as "Not a Contribution." + + "Contributor" shall mean Licensor and any individual or Legal Entity + on behalf of whom a Contribution has been received by Licensor and + subsequently incorporated within the Work. + + 2. Grant of Copyright License. Subject to the terms and conditions of + this License, each Contributor hereby grants to You a perpetual, + worldwide, non-exclusive, no-charge, royalty-free, irrevocable + copyright license to reproduce, prepare Derivative Works of, + publicly display, publicly perform, sublicense, and distribute the + Work and such Derivative Works in Source or Object form. + + 3. Grant of Patent License. Subject to the terms and conditions of + this License, each Contributor hereby grants to You a perpetual, + worldwide, non-exclusive, no-charge, royalty-free, irrevocable + (except as stated in this section) patent license to make, have made, + use, offer to sell, sell, import, and otherwise transfer the Work, + where such license applies only to those patent claims licensable + by such Contributor that are necessarily infringed by their + Contribution(s) alone or by combination of their Contribution(s) + with the Work to which such Contribution(s) was submitted. If You + institute patent litigation against any entity (including a + cross-claim or counterclaim in a lawsuit) alleging that the Work + or a Contribution incorporated within the Work constitutes direct + or contributory patent infringement, then any patent licenses + granted to You under this License for that Work shall terminate + as of the date such litigation is filed. + + 4. Redistribution. You may reproduce and distribute copies of the + Work or Derivative Works thereof in any medium, with or without + modifications, and in Source or Object form, provided that You + meet the following conditions: + + (a) You must give any other recipients of the Work or + Derivative Works a copy of this License; and + + (b) You must cause any modified files to carry prominent notices + stating that You changed the files; and + + (c) You must retain, in the Source form of any Derivative Works + that You distribute, all copyright, patent, trademark, and + attribution notices from the Source form of the Work, + excluding those notices that do not pertain to any part of + the Derivative Works; and + + (d) If the Work includes a "NOTICE" text file as part of its + distribution, then any Derivative Works that You distribute must + include a readable copy of the attribution notices contained + within such NOTICE file, excluding those notices that do not + pertain to any part of the Derivative Works, in at least one + of the following places: within a NOTICE text file distributed + as part of the Derivative Works; within the Source form or + documentation, if provided along with the Derivative Works; or, + within a display generated by the Derivative Works, if and + wherever such third-party notices normally appear. The contents + of the NOTICE file are for informational purposes only and + do not modify the License. You may add Your own attribution + notices within Derivative Works that You distribute, alongside + or as an addendum to the NOTICE text from the Work, provided + that such additional attribution notices cannot be construed + as modifying the License. + + You may add Your own copyright statement to Your modifications and + may provide additional or different license terms and conditions + for use, reproduction, or distribution of Your modifications, or + for any such Derivative Works as a whole, provided Your use, + reproduction, and distribution of the Work otherwise complies with + the conditions stated in this License. + + 5. Submission of Contributions. Unless You explicitly state otherwise, + any Contribution intentionally submitted for inclusion in the Work + by You to the Licensor shall be under the terms and conditions of + this License, without any additional terms or conditions. + Notwithstanding the above, nothing herein shall supersede or modify + the terms of any separate license agreement you may have executed + with Licensor regarding such Contributions. + + 6. Trademarks. This License does not grant permission to use the trade + names, trademarks, service marks, or product names of the Licensor, + except as required for reasonable and customary use in describing the + origin of the Work and reproducing the content of the NOTICE file. + + 7. Disclaimer of Warranty. Unless required by applicable law or + agreed to in writing, Licensor provides the Work (and each + Contributor provides its Contributions) on an "AS IS" BASIS, + WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or + implied, including, without limitation, any warranties or conditions + of TITLE, NON-INFRINGEMENT, MERCHANTABILITY, or FITNESS FOR A + PARTICULAR PURPOSE. You are solely responsible for determining the + appropriateness of using or redistributing the Work and assume any + risks associated with Your exercise of permissions under this License. + + 8. Limitation of Liability. In no event and under no legal theory, + whether in tort (including negligence), contract, or otherwise, + unless required by applicable law (such as deliberate and grossly + negligent acts) or agreed to in writing, shall any Contributor be + liable to You for damages, including any direct, indirect, special, + incidental, or consequential damages of any character arising as a + result of this License or out of the use or inability to use the + Work (including but not limited to damages for loss of goodwill, + work stoppage, computer failure or malfunction, or any and all + other commercial damages or losses), even if such Contributor + has been advised of the possibility of such damages. + + 9. Accepting Warranty or Additional Liability. While redistributing + the Work or Derivative Works thereof, You may choose to offer, + and charge a fee for, acceptance of support, warranty, indemnity, + or other liability obligations and/or rights consistent with this + License. However, in accepting such obligations, You may act only + on Your own behalf and on Your sole responsibility, not on behalf + of any other Contributor, and only if You agree to indemnify, + defend, and hold each Contributor harmless for any liability + incurred by, or claims asserted against, such Contributor by reason + of your accepting any such warranty or additional liability. + + END OF TERMS AND CONDITIONS + + APPENDIX: How to apply the Apache License to your work. + + To apply the Apache License to your work, attach the following + boilerplate notice, with the fields enclosed by brackets "[]" + replaced with your own identifying information. (Don't include + the brackets!) The text should be enclosed in the appropriate + comment syntax for the file format. We also recommend that a + file or class name and description of purpose be included on the + same "printed page" as the copyright notice for easier + identification within third-party archives. + + Copyright [yyyy] [name of copyright owner] + + Licensed under the Apache License, Version 2.0 (the "License"); + you may not use this file except in compliance with the License. + You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + + Unless required by applicable law or agreed to in writing, software + distributed under the License is distributed on an "AS IS" BASIS, + WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + See the License for the specific language governing permissions and + limitations under the License. \ No newline at end of file diff --git a/packages/logger/README.md b/packages/logger/README.md new file mode 100644 index 000000000000..d2b182ac38f7 --- /dev/null +++ b/packages/logger/README.md @@ -0,0 +1,12 @@ +# lodestar-logger + +![ES Version](https://img.shields.io/badge/ES-2020-yellow) +![Node Version](https://img.shields.io/badge/node-12.x-green) + +> This package is part of [ChainSafe's Lodestar](https://lodestar.chainsafe.io) project + +Common NodeJS logger for Lodestar binaries. Required for worker-threads to instantiate new loggers with consistent settings + +## License + +Apache-2.0 [ChainSafe Systems](https://chainsafe.io) diff --git a/packages/logger/package.json b/packages/logger/package.json new file mode 100644 index 000000000000..f89e09cd72c7 --- /dev/null +++ b/packages/logger/package.json @@ -0,0 +1,81 @@ +{ + "name": "@lodestar/logger", + "description": "Common NodeJS logger for Lodestar binaries", + "license": "Apache-2.0", + "author": "ChainSafe Systems", + "homepage": "https://github.com/ChainSafe/lodestar#readme", + "repository": { + "type": "git", + "url": "git+https://github.com:ChainSafe/lodestar.git" + }, + "bugs": { + "url": "https://github.com/ChainSafe/lodestar/issues" + }, + "version": "1.8.0", + "type": "module", + "exports": { + ".": { + "import": "./lib/index.js" + }, + "./browser": { + "import": "./lib/browser.js" + }, + "./env": { + "import": "./lib/env.js" + }, + "./node": { + "import": "./lib/node.js" + }, + "./empty": { + "import": "./lib/empty.js" + } + }, + "typesVersions": { + "*": { + "*": [ + "*", + "lib/*", + "lib/*/index" + ] + } + }, + "files": [ + "lib/**/*.d.ts", + "lib/**/*.js", + "lib/**/*.js.map", + "*.d.ts", + "*.js" + ], + "scripts": { + "clean": "rm -rf lib && rm -f *.tsbuildinfo", + "build": "tsc -p tsconfig.build.json", + "build:lib:watch": "yarn run build:lib --watch", + "build:release": "yarn clean && yarn build", + "build:types:watch": "yarn run build:types --watch", + "check-build": "node -e \"(async function() { await import('./lib/index.js') })()\"", + "check-types": "tsc", + "lint": "eslint --color --ext .ts src/ test/", + "lint:fix": "yarn run lint --fix", + "pretest": "yarn run check-types", + "test:unit": "mocha 'test/**/*.test.ts'", + "check-readme": "typescript-docs-verifier" + }, + "types": "lib/index.d.ts", + "dependencies": { + "@lodestar/utils": "1.8.0", + "winston": "^3.8.2", + "winston-daily-rotate-file": "^4.7.1", + "winston-transport": "^4.5.0" + }, + "devDependencies": { + "@types/triple-beam": "^1.3.2", + "triple-beam": "^1.3.0", + "rimraf": "^4.4.1" + }, + "keywords": [ + "ethereum", + "eth-consensus", + "beacon", + "blockchain" + ] +} diff --git a/packages/logger/src/browser.ts b/packages/logger/src/browser.ts new file mode 100644 index 000000000000..db65785a83f3 --- /dev/null +++ b/packages/logger/src/browser.ts @@ -0,0 +1,55 @@ +import winston from "winston"; +import Transport from "winston-transport"; +import {LogLevel, Logger} from "@lodestar/utils"; +import {createWinstonLogger} from "./winston.js"; + +export type BrowserLoggerOpts = { + module?: string; + level: LogLevel; +}; + +export function getBrowserLogger(opts: BrowserLoggerOpts): Logger { + return createWinstonLogger({level: opts.level, module: opts.module ?? ""}, [new BrowserConsole({level: opts.level})]); +} + +class BrowserConsole extends Transport { + name = "BrowserConsole"; + private levels: Record = { + error: 0, + warn: 1, + info: 2, + verbose: 3, + debug: 4, + trace: 5, + }; + + private methods: Record = { + error: "error", + warn: "warn", + info: "info", + verbose: "log", + debug: "log", + trace: "log", + }; + + constructor(opts: winston.transport.TransportStreamOptions | undefined) { + super(opts); + this.level = opts?.level && this.levels.hasOwnProperty(opts.level) ? opts.level : "info"; + } + + log(method: string | number, message: unknown): void { + setImmediate(() => { + this.emit("logged", method); + }); + + const val = this.levels[method as LogLevel]; + const mappedMethod = this.methods[method as LogLevel]; + + if (val <= this.levels[this.level as LogLevel]) { + // eslint-disable-next-line @typescript-eslint/ban-ts-comment + // @ts-expect-error + // eslint-disable-next-line @typescript-eslint/no-unsafe-call, no-console + console[mappedMethod](message); + } + } +} diff --git a/packages/logger/src/empty.ts b/packages/logger/src/empty.ts new file mode 100644 index 000000000000..24bd183db916 --- /dev/null +++ b/packages/logger/src/empty.ts @@ -0,0 +1,24 @@ +import {Logger} from "@lodestar/utils"; + +export function getEmptyLogger(): Logger { + return { + error: function error(): void { + // Do nothing + }, + warn: function warn(): void { + // Do nothing + }, + info: function info(): void { + // Do nothing + }, + verbose: function verbose(): void { + // Do nothing + }, + debug: function debug(): void { + // Do nothing + }, + trace: function trace(): void { + // Do nothing + }, + }; +} diff --git a/packages/logger/src/env.ts b/packages/logger/src/env.ts new file mode 100644 index 000000000000..15a3ea2cace0 --- /dev/null +++ b/packages/logger/src/env.ts @@ -0,0 +1,20 @@ +import {Logger} from "@lodestar/utils"; +import {LogLevel} from "@lodestar/utils"; +import {BrowserLoggerOpts, getBrowserLogger} from "./browser.js"; +import {getEmptyLogger} from "./empty.js"; + +export function getEnvLogLevel(): LogLevel | null { + if (process == null) return null; + if (process.env["LOG_LEVEL"]) return process.env["LOG_LEVEL"] as LogLevel; + if (process.env["DEBUG"]) return LogLevel.debug; + if (process.env["VERBOSE"]) return LogLevel.verbose; + return null; +} + +export function getEnvLogger(opts?: Partial): Logger { + const level = opts?.level ?? getEnvLogLevel(); + if (level != null) { + return getBrowserLogger({...opts, level}); + } + return getEmptyLogger(); +} diff --git a/packages/logger/src/index.ts b/packages/logger/src/index.ts new file mode 100644 index 000000000000..96d65789f80b --- /dev/null +++ b/packages/logger/src/index.ts @@ -0,0 +1 @@ +export * from "./interface.js"; diff --git a/packages/utils/src/logger/interface.ts b/packages/logger/src/interface.ts similarity index 62% rename from packages/utils/src/logger/interface.ts rename to packages/logger/src/interface.ts index 3c323feecdaa..05e74a54b3d9 100644 --- a/packages/utils/src/logger/interface.ts +++ b/packages/logger/src/interface.ts @@ -1,13 +1,5 @@ -import {LogData} from "./json.js"; - -export enum LogLevel { - error = "error", - warn = "warn", - info = "info", - verbose = "verbose", - debug = "debug", - trace = "trace", -} +import {LogLevel, Logger, LogHandler, LogData} from "@lodestar/utils"; +export {LogLevel, Logger, LogHandler, LogData}; export const logLevelNum: {[K in LogLevel]: number} = { [LogLevel.error]: 0, @@ -22,8 +14,6 @@ export const logLevelNum: {[K in LogLevel]: number} = { // eslint-disable-next-line @typescript-eslint/naming-convention export const LogLevels = Object.values(LogLevel); -export const defaultLogLevel = LogLevel.info; - export type LogFormat = "human" | "json"; export const logFormats: LogFormat[] = ["human", "json"]; @@ -34,32 +24,17 @@ export type EpochSlotOpts = { }; export enum TimestampFormatCode { DateRegular, + Hidden, EpochSlot, } export type TimestampFormat = | {format: TimestampFormatCode.DateRegular} + | {format: TimestampFormatCode.Hidden} | ({format: TimestampFormatCode.EpochSlot} & EpochSlotOpts); export interface LoggerOptions { level?: LogLevel; module?: string; format?: LogFormat; - hideTimestamp?: boolean; timestampFormat?: TimestampFormat; } - -export type LoggerChildOpts = { - module: string; -}; - -export type LogHandler = (message: string, context?: LogData, error?: Error) => void; - -export type Logger = { - error: LogHandler; - warn: LogHandler; - info: LogHandler; - verbose: LogHandler; - debug: LogHandler; - // custom - child(options: LoggerChildOpts): Logger; -}; diff --git a/packages/logger/src/node.ts b/packages/logger/src/node.ts new file mode 100644 index 000000000000..c7e231034512 --- /dev/null +++ b/packages/logger/src/node.ts @@ -0,0 +1,159 @@ +import path from "node:path"; +import DailyRotateFile from "winston-daily-rotate-file"; +import TransportStream from "winston-transport"; +import winston from "winston"; +import {Logger, LogLevel, logLevelNum, TimestampFormat} from "./interface.js"; +import {ConsoleDynamicLevel} from "./utils/consoleTransport.js"; +import {getFormat} from "./utils/format.js"; +import {WinstonLogger} from "./winston.js"; + +const DATE_PATTERN = "YYYY-MM-DD"; + +export type LoggerNodeOpts = { + level: LogLevel; + /** + * Enable file output transport if set + */ + file?: { + filepath: string; + /** + * Log level for file output transport + */ + level: LogLevel; + /** + * Rotation config for file output transport + */ + dailyRotate?: number; + }; + /** + * Module prefix for all logs + */ + module?: string; + /** + * Rendering format for logs, defaults to "human" + */ + format?: "human" | "json"; + /** + * Set specific log levels by module + */ + levelModule?: Record; + /** + * Enables relative to genesis timestamp format + * ``` + * timestampFormat = { + * format: TimestampFormatCode.EpochSlot, + * genesisTime: args.logFormatGenesisTime, + * secondsPerSlot: config.SECONDS_PER_SLOT, + * slotsPerEpoch: SLOTS_PER_EPOCH, + * } + * ``` + */ + timestampFormat?: TimestampFormat; +}; + +export type LoggerNodeChildOpts = { + module?: string; +}; + +export type LoggerNode = Logger & { + toOpts(): LoggerNodeOpts; + child(opts: LoggerNodeChildOpts): LoggerNode; +}; + +/** + * Setup a CLI logger, common for beacon, validator and dev commands + */ +export function getNodeLogger(opts: LoggerNodeOpts): LoggerNode { + return WinstonLoggerNode.fromNewTransports(opts); +} + +function getNodeLoggerTransports(opts: LoggerNodeOpts): winston.transport[] { + const consoleTransport = new ConsoleDynamicLevel({ + // Set defaultLevel, not level for dynamic level setting of ConsoleDynamicLvevel + defaultLevel: opts.level, + debugStdout: true, + handleExceptions: true, + }); + + if (opts.levelModule) { + for (const [module, level] of Object.entries(opts.levelModule)) { + consoleTransport.setModuleLevel(module, level); + } + } + + const transports: TransportStream[] = [consoleTransport]; + + // yargs populates with undefined if just set but with no arg + // $ ./bin/lodestar.js beacon --logFileDailyRotate + // args = { + // logFileDailyRotate: undefined, + // } + // `lodestar --logFileDailyRotate` -> enabled daily rotate with default value + // `lodestar --logFileDailyRotate 10` -> set daily rotate to custom value 10 + // `lodestar --logFileDailyRotate 0` -> disable daily rotate and accumulate in same file + if (opts.file) { + const filename = opts.file.filepath; + + transports.push( + opts.file.dailyRotate != null + ? new DailyRotateFile({ + level: opts.file.level, + //insert the date pattern in filename before the file extension. + filename: filename.replace(/\.(?=[^.]*$)|$/, "-%DATE%$&"), + datePattern: DATE_PATTERN, + handleExceptions: true, + maxFiles: opts.file.dailyRotate, + auditFile: path.join(path.dirname(filename), ".log_rotate_audit.json"), + }) + : new winston.transports.File({ + level: opts.file.level, + filename: filename, + handleExceptions: true, + }) + ); + } + + return transports; +} + +interface DefaultMeta { + module: string; +} + +export class WinstonLoggerNode extends WinstonLogger implements LoggerNode { + constructor(private readonly opts: LoggerNodeOpts, private readonly transports: winston.transport[]) { + const defaultMeta: DefaultMeta = {module: opts?.module || ""}; + super( + winston.createLogger({ + // Do not set level at the logger level. Always control by Transport, unless for testLogger + level: opts.level, + defaultMeta, + format: getFormat(opts), + transports, + exitOnError: false, + levels: logLevelNum, + }) + ); + } + + static fromNewTransports(opts: LoggerNodeOpts): WinstonLoggerNode { + return new WinstonLoggerNode(opts, getNodeLoggerTransports(opts)); + } + + // Return a new logger instance with different module and log level + // but a reference to the same transports, such that there's only one + // transport instance per tree of child loggers + child(opts: LoggerNodeChildOpts): LoggerNode { + return new WinstonLoggerNode( + { + ...this.opts, + module: [this.opts?.module, opts.module].filter(Boolean).join("/"), + }, + this.transports + ); + } + + toOpts(): LoggerNodeOpts { + return this.opts; + } +} diff --git a/packages/cli/src/util/loggerConsoleTransport.ts b/packages/logger/src/utils/consoleTransport.ts similarity index 97% rename from packages/cli/src/util/loggerConsoleTransport.ts rename to packages/logger/src/utils/consoleTransport.ts index 69ba70b54236..4a4ba3bcc4eb 100644 --- a/packages/cli/src/util/loggerConsoleTransport.ts +++ b/packages/logger/src/utils/consoleTransport.ts @@ -1,7 +1,7 @@ import winston, {Logger} from "winston"; // eslint-disable-next-line import/no-extraneous-dependencies import {LEVEL} from "triple-beam"; -import {LogLevel} from "@lodestar/utils"; +import {LogLevel} from "../interface.js"; interface DefaultMeta { module: string; diff --git a/packages/utils/src/logger/format.ts b/packages/logger/src/utils/format.ts similarity index 87% rename from packages/utils/src/logger/format.ts rename to packages/logger/src/utils/format.ts index 4f9aff995f3c..18575b16e246 100644 --- a/packages/utils/src/logger/format.ts +++ b/packages/logger/src/utils/format.ts @@ -1,7 +1,7 @@ import winston from "winston"; +import {LoggerOptions, TimestampFormatCode} from "../interface.js"; import {logCtxToJson, logCtxToString, LogData} from "./json.js"; -import {LoggerOptions, TimestampFormatCode} from "./interface.js"; -import {formatEpochSlotTime} from "./util.js"; +import {formatEpochSlotTime} from "./timeFormat.js"; const {format} = winston; @@ -31,7 +31,7 @@ export function getFormat(opts: LoggerOptions): Format { function humanReadableLogFormat(opts: LoggerOptions): Format { return format.combine( - ...(opts.hideTimestamp ? [] : [formatTimestamp(opts)]), + ...(opts.timestampFormat?.format === TimestampFormatCode.Hidden ? [] : [formatTimestamp(opts)]), format.colorize(), format.printf(humanReadableTemplateFn) ); @@ -57,7 +57,7 @@ function formatTimestamp(opts: LoggerOptions): Format { function jsonLogFormat(opts: LoggerOptions): Format { return format.combine( - ...(opts.hideTimestamp ? [] : [format.timestamp()]), + ...(opts.timestampFormat?.format === TimestampFormatCode.Hidden ? [] : [format.timestamp()]), format((_info) => { const info = _info as WinstonInfoArg; info.context = logCtxToJson(info.context); diff --git a/packages/utils/src/logger/json.ts b/packages/logger/src/utils/json.ts similarity index 96% rename from packages/utils/src/logger/json.ts rename to packages/logger/src/utils/json.ts index 8d3f5e87d333..f6f2d85487c7 100644 --- a/packages/utils/src/logger/json.ts +++ b/packages/logger/src/utils/json.ts @@ -1,6 +1,4 @@ -import {toHexString} from "../bytes.js"; -import {LodestarError} from "../errors.js"; -import {mapValues} from "../objects.js"; +import {LodestarError, mapValues, toHexString} from "@lodestar/utils"; const MAX_DEPTH = 0; diff --git a/packages/utils/src/logger/util.ts b/packages/logger/src/utils/timeFormat.ts similarity index 93% rename from packages/utils/src/logger/util.ts rename to packages/logger/src/utils/timeFormat.ts index 0e949db3b859..38ae0ee40ae8 100644 --- a/packages/utils/src/logger/util.ts +++ b/packages/logger/src/utils/timeFormat.ts @@ -1,4 +1,4 @@ -import {EpochSlotOpts} from "./interface.js"; +import {EpochSlotOpts} from "../interface.js"; /** * Formats time as: `EPOCH/SLOT_INDEX SECONDS.MILLISECONDS diff --git a/packages/utils/src/logger/winston.ts b/packages/logger/src/winston.ts similarity index 76% rename from packages/utils/src/logger/winston.ts rename to packages/logger/src/winston.ts index 91e175a41600..a169b168833a 100644 --- a/packages/utils/src/logger/winston.ts +++ b/packages/logger/src/winston.ts @@ -1,8 +1,8 @@ import winston from "winston"; import type {Logger as Winston} from "winston"; -import {Logger, LoggerOptions, LoggerChildOpts, LogLevel, logLevelNum} from "./interface.js"; -import {getFormat} from "./format.js"; -import {LogData} from "./json.js"; +import {Logger, LoggerOptions, LogLevel, logLevelNum} from "./interface.js"; +import {getFormat} from "./utils/format.js"; +import {LogData} from "./utils/json.js"; // # How to configure Winston log level? // @@ -37,7 +37,7 @@ export function createWinstonLogger(options: Partial = {}, transp } export class WinstonLogger implements Logger { - constructor(private readonly winston: Winston) {} + constructor(protected readonly winston: Winston) {} static fromOpts(options: Partial = {}, transports?: winston.transport[]): WinstonLogger { const defaultMeta: DefaultMeta = {module: options?.module || ""}; @@ -79,23 +79,6 @@ export class WinstonLogger implements Logger { this.createLogEntry(LogLevel.trace, message, context, error); } - child(options: LoggerChildOpts): WinstonLogger { - const parentMeta = this.winston.defaultMeta as DefaultMeta | undefined; - const childModule = [parentMeta?.module, options.module].filter(Boolean).join("/"); - const defaultMeta: DefaultMeta = {module: childModule}; - - // Same strategy as Winston's source .child. - // However, their implementation of child is to merge info objects where parent takes precedence, so it's - // impossible for child to overwrite 'module' field. Instead the winston class is cloned as defaultMeta - // overwritten completely. - // https://github.com/winstonjs/winston/blob/3f1dcc13cda384eb30fe3b941764e47a5a5efc26/lib/winston/logger.js#L47 - const childWinston = Object.create(this.winston) as typeof this.winston; - - childWinston.defaultMeta = defaultMeta; - - return new WinstonLogger(childWinston); - } - private createLogEntry(level: LogLevel, message: string, context?: LogData, error?: Error): void { // Note: logger does not run format.transform function unless it will actually write the log to the transport diff --git a/packages/logger/test/e2e/logger/workerLogger.ts b/packages/logger/test/e2e/logger/workerLogger.ts new file mode 100644 index 000000000000..0a4f1dd9207b --- /dev/null +++ b/packages/logger/test/e2e/logger/workerLogger.ts @@ -0,0 +1,19 @@ +import fs from "node:fs"; +import worker from "node:worker_threads"; +import {expose} from "@chainsafe/threads/worker"; + +const parentPort = worker.parentPort; +const workerData = worker.workerData as {logFilepath: string}; +if (!parentPort) throw Error("parentPort must be defined"); + +const file = fs.createWriteStream(workerData.logFilepath, {flags: "a"}); + +parentPort.on("message", (data) => { + // eslint-disable-next-line no-console + console.log(data); + file.write(data); +}); + +expose(() => { + // +}); diff --git a/packages/logger/test/e2e/logger/workerLoggerHandler.ts b/packages/logger/test/e2e/logger/workerLoggerHandler.ts new file mode 100644 index 000000000000..3ff095fc4f89 --- /dev/null +++ b/packages/logger/test/e2e/logger/workerLoggerHandler.ts @@ -0,0 +1,32 @@ +import worker_threads from "node:worker_threads"; +import {spawn, Worker} from "@chainsafe/threads"; + +export type LoggerWorker = { + log(data: string): void; + close(): Promise; +}; + +type WorkerData = {logFilepath: string}; + +export async function getLoggerWorker(opts: WorkerData): Promise { + const workerThreadjs = new Worker("./workerLogger.js", {workerData: opts}); + const worker = workerThreadjs as unknown as worker_threads.Worker; + + // eslint-disable-next-line @typescript-eslint/no-explicit-any + await spawn(workerThreadjs, { + // A Lodestar Node may do very expensive task at start blocking the event loop and causing + // the initialization to timeout. The number below is big enough to almost disable the timeout + timeout: 5 * 60 * 1000, + // TODO: types are broken on spawn, which claims that `NetworkWorkerApi` does not satifies its contrains + }); + + return { + log(data) { + worker.postMessage(data); + }, + + async close() { + await workerThreadjs.terminate(); + }, + }; +} diff --git a/packages/logger/test/e2e/logger/workerLogs.test.ts b/packages/logger/test/e2e/logger/workerLogs.test.ts new file mode 100644 index 000000000000..52b8b5efa4b1 --- /dev/null +++ b/packages/logger/test/e2e/logger/workerLogs.test.ts @@ -0,0 +1,76 @@ +import path from "node:path"; +import fs from "node:fs"; +import {fileURLToPath} from "node:url"; +import {expect} from "chai"; +import {sleep} from "@lodestar/utils"; +import {LoggerWorker, getLoggerWorker} from "./workerLoggerHandler.js"; + +// Global variable __dirname no longer available in ES6 modules. +// Solutions: https://stackoverflow.com/questions/46745014/alternative-for-dirname-in-node-js-when-using-es6-modules +// eslint-disable-next-line @typescript-eslint/naming-convention +const __dirname = path.dirname(fileURLToPath(import.meta.url)); + +describe("worker logs", function () { + this.timeout(60_000); + + const logFilepath = path.join(__dirname, "../../../test-logs/test_worker_logs.log"); + let loggerWorker: LoggerWorker; + + beforeEach(async () => { + // Touch log file + fs.mkdirSync(path.dirname(logFilepath), {recursive: true}); + fs.writeFileSync(logFilepath, ""); + // Create worker before each test since the write stream is created once + loggerWorker = await getLoggerWorker({logFilepath}); + }); + + afterEach(async () => { + // Guard against before() erroring + if (loggerWorker != null) await loggerWorker.close(); + // Remove log file + fs.rmSync(logFilepath, {force: true}); + }); + + it("mainthread writes to file", async () => { + const logTextMainThread = "test-log-mainthread"; + fs.createWriteStream(logFilepath, {flags: "a"}).write(logTextMainThread); + + const data = await waitForFileSize(logFilepath, logTextMainThread.length); + expect(data).includes(logTextMainThread); + }); + + it("worker writes to file", async () => { + const logTextWorker = "test-log-worker"; + loggerWorker.log(logTextWorker); + + const data = await waitForFileSize(logFilepath, logTextWorker.length); + expect(data).includes(logTextWorker); + }); + + it("concurrent write from two write streams in different threads", async () => { + const logTextWorker = "test-log-worker"; + const logTextMainThread = "test-log-mainthread"; + + const file = fs.createWriteStream(logFilepath, {flags: "a"}); + + loggerWorker.log(logTextWorker); + file.write(logTextMainThread + "\n"); + + const data = await waitForFileSize(logFilepath, logTextWorker.length + logTextMainThread.length); + expect(data).includes(logTextWorker); + expect(data).includes(logTextMainThread); + }); +}); + +async function waitForFileSize(filepath: string, minSize: number): Promise { + for (let i = 0; i < 10; i++) { + const data = fs.readFileSync(filepath, "utf8"); + if (data.length >= minSize) { + return data; + } + await sleep(100); + } + + const data = fs.readFileSync(filepath, "utf8"); + throw Error(`Timeout waiting for ${filepath} to have size ${minSize}, current size ${data.length}\n${data}`); +} diff --git a/packages/logger/test/setup.ts b/packages/logger/test/setup.ts new file mode 100644 index 000000000000..b83e6cb78511 --- /dev/null +++ b/packages/logger/test/setup.ts @@ -0,0 +1,6 @@ +import chai from "chai"; +import chaiAsPromised from "chai-as-promised"; +import sinonChai from "sinon-chai"; + +chai.use(chaiAsPromised); +chai.use(sinonChai); diff --git a/packages/cli/test/unit/util/logger.test.ts b/packages/logger/test/unit/logger.test.ts similarity index 95% rename from packages/cli/test/unit/util/logger.test.ts rename to packages/logger/test/unit/logger.test.ts index 9fb7f9bb8505..26caf910dd27 100644 --- a/packages/cli/test/unit/util/logger.test.ts +++ b/packages/logger/test/unit/logger.test.ts @@ -1,6 +1,6 @@ import {expect} from "chai"; import sinon from "sinon"; -import {shouldDeleteLogFile} from "../../../src/util/logger.js"; +import {shouldDeleteLogFile} from "../../../cli/src/util/logger.js"; describe("shouldDeleteLogFile", function () { const prefix = "beacon"; diff --git a/packages/utils/test/unit/logger/json.test.ts b/packages/logger/test/unit/logger/json.test.ts similarity index 97% rename from packages/utils/test/unit/logger/json.test.ts rename to packages/logger/test/unit/logger/json.test.ts index 6b423de50d40..06352fc5f171 100644 --- a/packages/utils/test/unit/logger/json.test.ts +++ b/packages/logger/test/unit/logger/json.test.ts @@ -2,8 +2,8 @@ import "../../setup.js"; import {expect} from "chai"; import {fromHexString, toHexString} from "@chainsafe/ssz"; -import {LodestarError} from "../../../src/index.js"; -import {logCtxToJson, logCtxToString} from "../../../src/logger/json.js"; +import {LodestarError} from "@lodestar/utils"; +import {logCtxToJson, logCtxToString} from "../../../src/utils/json.js"; describe("Json helper", () => { const circularReference = {}; diff --git a/packages/utils/test/unit/logger/util.test.ts b/packages/logger/test/unit/logger/timeFormat.test.ts similarity index 91% rename from packages/utils/test/unit/logger/util.test.ts rename to packages/logger/test/unit/logger/timeFormat.test.ts index 2ceaa0613cc4..62640ff48c2c 100644 --- a/packages/utils/test/unit/logger/util.test.ts +++ b/packages/logger/test/unit/logger/timeFormat.test.ts @@ -1,6 +1,6 @@ import "../../setup.js"; import {expect} from "chai"; -import {formatEpochSlotTime} from "../../../src/logger/util.js"; +import {formatEpochSlotTime} from "../../../src/utils/timeFormat.js"; describe("logger / util / formatEpochSlotTime", () => { const nowSec = 1619171569; diff --git a/packages/utils/test/unit/logger/winston.test.ts b/packages/logger/test/unit/logger/winston.test.ts similarity index 85% rename from packages/utils/test/unit/logger/winston.test.ts rename to packages/logger/test/unit/logger/winston.test.ts index 7357bab39e4a..5ad5bda9b8b9 100644 --- a/packages/utils/test/unit/logger/winston.test.ts +++ b/packages/logger/test/unit/logger/winston.test.ts @@ -2,7 +2,9 @@ import "../../setup.js"; import {expect} from "chai"; import {MESSAGE} from "triple-beam"; import Transport from "winston-transport"; -import {LogData, LodestarError, LogFormat, logFormats, createWinstonLogger} from "../../../src/index.js"; +import {LodestarError, LogLevel} from "@lodestar/utils"; +import {LogData, LogFormat, logFormats, TimestampFormatCode} from "../../../src/index.js"; +import {WinstonLoggerNode} from "../../../src/node.js"; type WinstonLog = {[MESSAGE]: string}; @@ -77,7 +79,10 @@ describe("winston logger", () => { for (const format of logFormats) { it(`${id} ${format} output`, async () => { const memoryTransport = new MemoryTransport(); - const logger = createWinstonLogger({format, hideTimestamp: true}, [memoryTransport]); + const logger = new WinstonLoggerNode( + {level: LogLevel.info, format, timestampFormat: {format: TimestampFormatCode.Hidden}}, + [memoryTransport] + ); logger.warn(message, context, error); expect(memoryTransport.getLogs()).deep.equals([output[format]]); @@ -89,7 +94,10 @@ describe("winston logger", () => { describe("child logger", () => { it("Should parse child module", async () => { const memoryTransport = new MemoryTransport(); - const loggerA = createWinstonLogger({hideTimestamp: true, module: "a"}, [memoryTransport]); + const loggerA = new WinstonLoggerNode( + {level: LogLevel.info, timestampFormat: {format: TimestampFormatCode.Hidden}, module: "a"}, + [memoryTransport] + ); const loggerAB = loggerA.child({module: "b"}); const loggerABC = loggerAB.child({module: "c"}); diff --git a/packages/cli/test/unit/util/loggerTransport.test.ts b/packages/logger/test/unit/loggerTransport.test.ts similarity index 85% rename from packages/cli/test/unit/util/loggerTransport.test.ts rename to packages/logger/test/unit/loggerTransport.test.ts index 73e31fbaf64d..255e804dd2b0 100644 --- a/packages/cli/test/unit/util/loggerTransport.test.ts +++ b/packages/logger/test/unit/loggerTransport.test.ts @@ -1,10 +1,9 @@ import fs from "node:fs"; import path from "node:path"; -import rimraf from "rimraf"; import {expect} from "chai"; -import {config} from "@lodestar/config/default"; -import {Logger, LodestarError, LogData, LogFormat, logFormats, LogLevel} from "@lodestar/utils"; -import {getCliLogger, LogArgs, LOG_FILE_DISABLE_KEYWORD} from "../../../src/util/logger.js"; +import {LodestarError, LogData, LogLevel} from "@lodestar/utils"; +import {LogFormat, TimestampFormatCode, logFormats} from "../../src/index.js"; +import {LoggerNode, LoggerNodeOpts, getNodeLogger} from "../../src/node.js"; describe("winston logger format and options", () => { type TestCase = { @@ -61,7 +60,11 @@ describe("winston logger format and options", () => { it(`${id} ${format} output`, async () => { stdoutHook = hookProcessStdout(); - const logger = getCliLoggerTest({logFormat: format}); + const logger = getNodeLogger({ + level: LogLevel.info, + format, + timestampFormat: {format: TimestampFormatCode.Hidden}, + }); logger.warn(message, context, error); @@ -80,7 +83,12 @@ describe("winston dynamic level by module", () => { afterEach(() => stdoutHook?.restore()); it("Should log to child at a lower logLevel", async () => { - const loggerA = getCliLoggerTest({logPrefix: "a", logLevelModule: [`a/b=${LogLevel.debug}`]}); + const loggerA = getNodeLoggerTest({ + module: "a", + levelModule: { + "a/b": LogLevel.debug, + }, + }); stdoutHook = hookProcessStdout(); @@ -119,7 +127,7 @@ describe("winston transport log to file", () => { const filenameRx = /^child-logger-test/; const filepath = path.join(tmpDir, filename); - const logger = getCliLoggerTest({logPrefix: "a", logFile: filepath}); + const logger = getNodeLoggerTest({module: "a", file: {filepath, level: LogLevel.info}}); stdoutHook = hookProcessStdout(); @@ -134,17 +142,16 @@ describe("winston transport log to file", () => { }); after(() => { - rimraf.sync(tmpDir); + fs.rmSync(tmpDir, {recursive: true}); }); }); -function getCliLoggerTest(logArgs: Partial): Logger { - return getCliLogger( - {logFile: LOG_FILE_DISABLE_KEYWORD, ...logArgs}, - {defaultLogFilepath: "logger_transport_test.log"}, - config, - {hideTimestamp: true} - ).logger; +function getNodeLoggerTest(opts: Partial): LoggerNode { + return getNodeLogger({ + level: LogLevel.info, + timestampFormat: {format: TimestampFormatCode.Hidden}, + ...opts, + }); } /** Wait for file to exist have some content, then return its contents */ diff --git a/packages/logger/test/utils/chai.ts b/packages/logger/test/utils/chai.ts new file mode 100644 index 000000000000..3c1e855021be --- /dev/null +++ b/packages/logger/test/utils/chai.ts @@ -0,0 +1,9 @@ +import {expect} from "chai"; + +export function expectDeepEquals(a: T, b: T, message?: string): void { + expect(a).deep.equals(b, message); +} + +export function expectEquals(a: T, b: T, message?: string): void { + expect(a).equals(b, message); +} diff --git a/packages/logger/tsconfig.build.json b/packages/logger/tsconfig.build.json new file mode 100644 index 000000000000..bac394399f4e --- /dev/null +++ b/packages/logger/tsconfig.build.json @@ -0,0 +1,7 @@ +{ + "extends": "../../tsconfig.build.json", + "include": ["src"], + "compilerOptions": { + "outDir": "./lib" + } +} diff --git a/packages/logger/tsconfig.e2e.json b/packages/logger/tsconfig.e2e.json new file mode 100644 index 000000000000..cedf626f4124 --- /dev/null +++ b/packages/logger/tsconfig.e2e.json @@ -0,0 +1,7 @@ +{ + "extends": "../../tsconfig.e2e.json", + "include": [ + "src", + "test" + ], +} \ No newline at end of file diff --git a/packages/logger/tsconfig.json b/packages/logger/tsconfig.json new file mode 100644 index 000000000000..b29a7b46c4b1 --- /dev/null +++ b/packages/logger/tsconfig.json @@ -0,0 +1,4 @@ +{ + "extends": "../../tsconfig.json", + "compilerOptions": {} +} diff --git a/packages/prover/package.json b/packages/prover/package.json index 0cd4d3dd1850..dfc950a1ec2a 100644 --- a/packages/prover/package.json +++ b/packages/prover/package.json @@ -79,6 +79,7 @@ "yargs": "^17.7.1" }, "devDependencies": { + "@lodestar/logger": "^1.8.0", "@types/http-proxy": "^1.17.10", "@types/yargs": "^17.0.24", "axios": "^1.3.4", diff --git a/packages/prover/src/utils/logger.ts b/packages/prover/src/utils/logger.ts index 9035993833b2..8046d7eaba77 100644 --- a/packages/prover/src/utils/logger.ts +++ b/packages/prover/src/utils/logger.ts @@ -1,87 +1,15 @@ -import winston from "winston"; -import Transport from "winston-transport"; -import {LogData, Logger, LoggerChildOpts, createWinstonLogger} from "@lodestar/utils"; +import {Logger} from "@lodestar/utils"; +import {getBrowserLogger} from "@lodestar/logger/browser"; +import {getEmptyLogger} from "@lodestar/logger/empty"; import {LogOptions} from "../interfaces.js"; -type BrowserLogLevels = "error" | "warn" | "info" | "debug"; - -class BrowserConsole extends Transport { - name = "BrowserConsole"; - private levels: Record = { - error: 0, - warn: 1, - info: 2, - debug: 4, - }; - - private methods: Record = { - error: "error", - warn: "warn", - info: "info", - debug: "log", - }; - - constructor(opts: winston.transport.TransportStreamOptions | undefined) { - super(opts); - this.level = opts?.level && this.levels.hasOwnProperty(opts.level) ? opts.level : "info"; - } - - log(method: string | number, message: unknown): void { - setImmediate(() => { - this.emit("logged", method); - }); - - const val = this.levels[method as BrowserLogLevels]; - const mappedMethod = this.methods[method as BrowserLogLevels]; - - if (val <= this.levels[this.level as BrowserLogLevels]) { - // eslint-disable-next-line @typescript-eslint/ban-ts-comment - // @ts-expect-error - // eslint-disable-next-line @typescript-eslint/no-unsafe-call, no-console - console[mappedMethod](message); - } - } -} - -const emptyLogger: Logger = { - // eslint-disable-next-line func-names - error: function (_message: string, _context?: LogData, _error?: Error | undefined): void { - // Do nothing - }, - // eslint-disable-next-line func-names - warn: function (_message: string, _context?: LogData, _error?: Error | undefined): void { - // Do nothing - }, - // eslint-disable-next-line func-names - info: function (_message: string, _context?: LogData, _error?: Error | undefined): void { - // Do nothing - }, - // eslint-disable-next-line func-names - verbose: function (_message: string, _context?: LogData, _error?: Error | undefined): void { - // Do nothing - }, - // eslint-disable-next-line func-names - debug: function (_message: string, _context?: LogData, _error?: Error | undefined): void { - // Do nothing - }, - // eslint-disable-next-line func-names - child: function (_options: LoggerChildOpts): Logger { - return emptyLogger; - }, -}; - export function getLogger(opts: LogOptions): Logger { if (opts.logger) return opts.logger; - // Code is running in the node environment - if (opts.logLevel && process !== undefined) { - return createWinstonLogger({level: opts.logLevel, module: "prover"}, [new winston.transports.Console()]); - } - - if (opts.logLevel && process === undefined) { - return createWinstonLogger({level: opts.logLevel, module: "prover"}, [new BrowserConsole({level: opts.logLevel})]); + if (opts.logLevel) { + return getBrowserLogger({level: opts.logLevel}); } // For the case when user don't want to fill in the logs of consumer browser - return emptyLogger; + return getEmptyLogger(); } diff --git a/packages/prover/test/mocks/logger_mock.ts b/packages/prover/test/mocks/logger_mock.ts deleted file mode 100644 index dbcd11558595..000000000000 --- a/packages/prover/test/mocks/logger_mock.ts +++ /dev/null @@ -1,11 +0,0 @@ -import sinon from "sinon"; -import {LogLevel, Logger} from "@lodestar/utils"; - -export const createMockLogger = (logLevel: LogLevel = LogLevel.info): Logger => ({ - info: sinon.stub(), - error: sinon.stub(), - warn: sinon.stub(), - debug: sinon.stub(), - verbose: sinon.stub(), - child: () => createMockLogger(logLevel), -}); diff --git a/packages/prover/test/mocks/request_handler.ts b/packages/prover/test/mocks/request_handler.ts index d762a1d6b100..5f474166a4ae 100644 --- a/packages/prover/test/mocks/request_handler.ts +++ b/packages/prover/test/mocks/request_handler.ts @@ -1,8 +1,8 @@ import sinon from "sinon"; import {NetworkName} from "@lodestar/config/networks"; import {ForkConfig} from "@lodestar/config"; +import {getEnvLogger} from "@lodestar/logger/env"; import {ELVerifiedRequestHandlerOpts} from "../../src/interfaces.js"; -import {createMockLogger} from "../mocks/logger_mock.js"; import {ProofProvider} from "../../src/proof_provider/proof_provider.js"; import {ELRequestPayload, ELResponse} from "../../src/types.js"; import {ELBlock} from "../../src/types.js"; @@ -36,7 +36,7 @@ export function generateReqHandlerOptionsMock( const options = { handler: sinon.stub(), - logger: createMockLogger(), + logger: getEnvLogger(), proofProvider: { getExecutionPayload: sinon.stub().resolves(executionPayload), } as unknown as ProofProvider, diff --git a/packages/prover/test/unit/utils/execution.test.ts b/packages/prover/test/unit/utils/execution.test.ts index 0c5800133286..dc2702e5f9d0 100644 --- a/packages/prover/test/unit/utils/execution.test.ts +++ b/packages/prover/test/unit/utils/execution.test.ts @@ -2,10 +2,10 @@ import {expect} from "chai"; import chai from "chai"; import chaiAsPromised from "chai-as-promised"; import deepmerge from "deepmerge"; +import {getEnvLogger} from "@lodestar/logger/env"; import {ELProof, ELStorageProof} from "../../../src/types.js"; import {isValidAccount, isValidStorageKeys} from "../../../src/utils/validation.js"; import {invalidStorageProof, validStorageProof} from "../../fixtures/index.js"; -import {createMockLogger} from "../../mocks/logger_mock.js"; import eoaProof from "../../fixtures/sepolia/eth_getBalance_eoa.json" assert {type: "json"}; import {hexToBuffer} from "../../../src/utils/conversion.js"; @@ -19,6 +19,8 @@ delete invalidAccountProof.accountProof[0]; chai.use(chaiAsPromised); describe("uitls/execution", () => { + const logger = getEnvLogger(); + describe("isValidAccount", () => { it("should return true if account is valid", async () => { await expect( @@ -26,7 +28,7 @@ describe("uitls/execution", () => { proof: validAccountProof, address, stateRoot: validStateRoot, - logger: createMockLogger(), + logger, }) ).eventually.to.be.true; }); @@ -44,7 +46,7 @@ describe("uitls/execution", () => { proof, address, stateRoot, - logger: createMockLogger(), + logger, }) ).eventually.to.be.false; }); @@ -58,7 +60,7 @@ describe("uitls/execution", () => { proof: invalidAccountProof, address, stateRoot, - logger: createMockLogger(), + logger, }) ).eventually.to.be.false; }); @@ -72,7 +74,7 @@ describe("uitls/execution", () => { isValidStorageKeys({ proof: validStorageProof, storageKeys, - logger: createMockLogger(), + logger, }) ).eventually.to.be.true; }); @@ -82,7 +84,7 @@ describe("uitls/execution", () => { await expect( isValidStorageKeys({ - logger: createMockLogger(), + logger, proof: invalidStorageProof, storageKeys, }) @@ -106,7 +108,7 @@ describe("uitls/execution", () => { isValidStorageKeys({ proof, storageKeys, - logger: createMockLogger(), + logger, }) ).eventually.to.be.false; }); @@ -122,7 +124,7 @@ describe("uitls/execution", () => { isValidStorageKeys({ proof, storageKeys, - logger: createMockLogger(), + logger, }) ).eventually.to.be.true; }); diff --git a/packages/reqresp/package.json b/packages/reqresp/package.json index b7cbc41fac71..65ec5b9986ce 100644 --- a/packages/reqresp/package.json +++ b/packages/reqresp/package.json @@ -66,6 +66,7 @@ "varint": "^6.0.0" }, "devDependencies": { + "@lodestar/logger": "^1.8.0", "@lodestar/types": "^1.8.0" }, "peerDependencies": { diff --git a/packages/reqresp/test/mocks/logger.ts b/packages/reqresp/test/mocks/logger.ts deleted file mode 100644 index 86eadf629b4c..000000000000 --- a/packages/reqresp/test/mocks/logger.ts +++ /dev/null @@ -1,11 +0,0 @@ -import sinon from "sinon"; -import {Logger} from "@lodestar/utils"; - -export const createStubbedLogger = (): Logger => ({ - debug: sinon.stub(), - info: sinon.stub(), - error: sinon.stub(), - warn: sinon.stub(), - verbose: sinon.stub(), - child: sinon.stub(), -}); diff --git a/packages/reqresp/test/unit/ReqResp.test.ts b/packages/reqresp/test/unit/ReqResp.test.ts index 743633e3e44c..26a68ce02d25 100644 --- a/packages/reqresp/test/unit/ReqResp.test.ts +++ b/packages/reqresp/test/unit/ReqResp.test.ts @@ -2,11 +2,11 @@ import {expect} from "chai"; import {Libp2p} from "libp2p"; import sinon from "sinon"; import {Logger} from "@lodestar/utils"; +import {getEmptyLogger} from "@lodestar/logger/empty"; import {RespStatus} from "../../src/interface.js"; import {ReqResp} from "../../src/ReqResp.js"; import {getEmptyHandler, sszSnappyPing} from "../fixtures/messages.js"; import {numberToStringProtocol, numberToStringProtocolDialOnly, pingProtocol} from "../fixtures/protocols.js"; -import {createStubbedLogger} from "../mocks/logger.js"; import {MockLibP2pStream} from "../utils/index.js"; import {responseEncode} from "../utils/response.js"; @@ -35,7 +35,7 @@ describe("ResResp", () => { handle: sinon.spy(), } as unknown as Libp2p; - logger = createStubbedLogger(); + logger = getEmptyLogger(); reqresp = new ReqResp({ libp2p, diff --git a/packages/reqresp/test/unit/request/index.test.ts b/packages/reqresp/test/unit/request/index.test.ts index c05392b97853..af8fc5fff09f 100644 --- a/packages/reqresp/test/unit/request/index.test.ts +++ b/packages/reqresp/test/unit/request/index.test.ts @@ -4,11 +4,11 @@ import {pipe} from "it-pipe"; import {expect} from "chai"; import {Libp2p} from "libp2p"; import sinon from "sinon"; -import {Logger, LodestarError, sleep} from "@lodestar/utils"; +import {getEmptyLogger} from "@lodestar/logger/empty"; +import {LodestarError, sleep} from "@lodestar/utils"; import {RequestError, RequestErrorCode, sendRequest, SendRequestOpts} from "../../../src/request/index.js"; import {Protocol, MixedProtocol, ResponseIncoming} from "../../../src/types.js"; import {getEmptyHandler, sszSnappyPing} from "../../fixtures/messages.js"; -import {createStubbedLogger} from "../../mocks/logger.js"; import {getValidPeerId} from "../../utils/peer.js"; import {MockLibP2pStream} from "../../utils/index.js"; import {responseEncode} from "../../utils/response.js"; @@ -17,8 +17,8 @@ import {expectRejectedWithLodestarError} from "../../utils/errors.js"; import {pingProtocol} from "../../fixtures/protocols.js"; describe("request / sendRequest", () => { + const logger = getEmptyLogger(); let controller: AbortController; - let logger: Logger; let peerId: PeerId; let libp2p: Libp2p; const sandbox = sinon.createSandbox(); @@ -50,7 +50,6 @@ describe("request / sendRequest", () => { beforeEach(() => { controller = new AbortController(); peerId = getValidPeerId(); - logger = createStubbedLogger(); }); afterEach(() => { diff --git a/packages/reqresp/test/unit/response/index.test.ts b/packages/reqresp/test/unit/response/index.test.ts index 06cc37f36c25..d26be58f67d4 100644 --- a/packages/reqresp/test/unit/response/index.test.ts +++ b/packages/reqresp/test/unit/response/index.test.ts @@ -1,11 +1,11 @@ import {PeerId} from "@libp2p/interface-peer-id"; import {expect} from "chai"; -import {LodestarError, Logger, fromHex} from "@lodestar/utils"; +import {LodestarError, fromHex} from "@lodestar/utils"; +import {getEmptyLogger} from "@lodestar/logger/empty"; import {Protocol, RespStatus} from "../../../src/index.js"; import {ReqRespRateLimiter} from "../../../src/rate_limiter/ReqRespRateLimiter.js"; import {handleRequest} from "../../../src/response/index.js"; import {sszSnappyPing} from "../../fixtures/messages.js"; -import {createStubbedLogger} from "../../mocks/logger.js"; import {expectRejectedWithLodestarError} from "../../utils/errors.js"; import {MockLibP2pStream, expectEqualByteChunks} from "../../utils/index.js"; import {getValidPeerId} from "../../utils/peer.js"; @@ -43,14 +43,13 @@ const testCases: { ]; describe("response / handleRequest", () => { + const logger = getEmptyLogger(); let controller: AbortController; - let logger: Logger; let peerId: PeerId; beforeEach(() => { controller = new AbortController(); peerId = getValidPeerId(); - logger = createStubbedLogger(); }); afterEach(() => controller.abort()); diff --git a/packages/state-transition/test/perf/misc/arrayCreation.test.ts b/packages/state-transition/test/perf/misc/arrayCreation.test.ts index 75a8dffd7520..8fd52ff99e27 100644 --- a/packages/state-transition/test/perf/misc/arrayCreation.test.ts +++ b/packages/state-transition/test/perf/misc/arrayCreation.test.ts @@ -1,7 +1,4 @@ -import {profilerLogger} from "../../utils/logger.js"; - describe.skip("array creation", function () { - const logger = profilerLogger(); const testCases: {id: string; fn: (n: number) => void}[] = [ { id: "Array.from(() => 0)", @@ -39,7 +36,8 @@ describe.skip("array creation", function () { } const to = process.hrtime.bigint(); const diffMs = Number(to - from) / 1e6; - logger.info(`${id}: ${diffMs / opsRun} ms`); + // eslint-disable-next-line no-console + console.log(`${id}: ${diffMs / opsRun} ms`); }); } }); diff --git a/packages/state-transition/test/perf/misc/bitopts.test.ts b/packages/state-transition/test/perf/misc/bitopts.test.ts index 5e924e515a8f..93df681bb3e2 100644 --- a/packages/state-transition/test/perf/misc/bitopts.test.ts +++ b/packages/state-transition/test/perf/misc/bitopts.test.ts @@ -1,9 +1,7 @@ import {FLAG_PREV_SOURCE_ATTESTER, FLAG_UNSLASHED} from "../../../src/index.js"; -import {profilerLogger} from "../../utils/logger.js"; describe.skip("bit opts", function () { this.timeout(0); - const logger = profilerLogger(); it("Benchmark bitshift", () => { const validators = 200_000; // Prater validators @@ -16,6 +14,7 @@ describe.skip("bit opts", function () { } const to = process.hrtime.bigint(); const diffMs = Number(to - from) / 1e6; - logger.info(`Time spent on OR in getAttestationDeltas: ${diffMs * ((orOptsPerRun * validators) / opsRun)} ms`); + // eslint-disable-next-line no-console + console.log(`Time spent on OR in getAttestationDeltas: ${diffMs * ((orOptsPerRun * validators) / opsRun)} ms`); }); }); diff --git a/packages/state-transition/test/perf/util.ts b/packages/state-transition/test/perf/util.ts index 88c3abdb8a2a..72bc2a17ad36 100644 --- a/packages/state-transition/test/perf/util.ts +++ b/packages/state-transition/test/perf/util.ts @@ -28,7 +28,6 @@ import { BeaconStatePhase0, BeaconStateAltair, } from "../../src/types.js"; -import {profilerLogger} from "../utils/logger.js"; import {interopPubkeysCached} from "../utils/interop.js"; import {getNextSyncCommittee} from "../../src/util/syncCommittee.js"; import {getEffectiveBalanceIncrements} from "../../src/cache/effectiveBalanceIncrements.js"; @@ -41,7 +40,6 @@ let phase0SignedBlock: phase0.SignedBeaconBlock | null = null; let altairState: BeaconStateAltair | null = null; let altairCachedState23637: CachedBeaconStateAltair | null = null; let altairCachedState23638: CachedBeaconStateAltair | null = null; -const logger = profilerLogger(); /** * Number of validators in prater is 210000 as of May 2021 @@ -119,10 +117,6 @@ export function generatePerfTestCachedStatePhase0(opts?: {goBackOneSlot: boolean // no justificationBits phase0State = ssz.phase0.BeaconState.toViewDU(state); - logger.verbose("Loaded phase0 state", { - slot: state.slot, - numValidators: state.validators.length, - }); // cache roots phase0State.hashTreeRoot(); @@ -277,10 +271,6 @@ export function generatePerformanceStateAltair(pubkeysArg?: Uint8Array[]): Beaco state.nextSyncCommittee = syncCommittee; altairState = ssz.altair.BeaconState.toViewDU(state); - logger.verbose("Loaded phase0 state", { - slot: altairState.slot, - numValidators: altairState.validators.length, - }); // cache roots altairState.hashTreeRoot(); } @@ -303,7 +293,6 @@ export function generatePerformanceBlockPhase0(): phase0.SignedBeaconBlock { ); // eth1Data, graffiti, attestations phase0SignedBlock = block; - logger.verbose("Loaded block", {slot: phase0SignedBlock.message.slot}); } return phase0SignedBlock; diff --git a/packages/state-transition/test/utils/logger.ts b/packages/state-transition/test/utils/logger.ts deleted file mode 100644 index d54e0c95464d..000000000000 --- a/packages/state-transition/test/utils/logger.ts +++ /dev/null @@ -1,5 +0,0 @@ -import {createWinstonLogger, Logger} from "@lodestar/utils"; - -export function profilerLogger(): Logger { - return createWinstonLogger(); -} diff --git a/packages/utils/src/index.ts b/packages/utils/src/index.ts index 31dd976e090e..bcb0bf27109f 100644 --- a/packages/utils/src/index.ts +++ b/packages/utils/src/index.ts @@ -1,10 +1,10 @@ -export * from "./logger/index.js"; export * from "./yaml/index.js"; export * from "./assert.js"; export * from "./bytes.js"; export * from "./err.js"; export * from "./errors.js"; export * from "./format.js"; +export * from "./logger.js"; export * from "./map.js"; export * from "./math.js"; export * from "./objects.js"; diff --git a/packages/utils/src/logger.ts b/packages/utils/src/logger.ts new file mode 100644 index 000000000000..1ff559157d7e --- /dev/null +++ b/packages/utils/src/logger.ts @@ -0,0 +1,21 @@ +/** + * Interface of a generic Lodestar logger. For implementations, see `@lodestar/logger` + */ +export type Logger = Record; + +export enum LogLevel { + error = "error", + warn = "warn", + info = "info", + verbose = "verbose", + debug = "debug", + trace = "trace", +} + +// eslint-disable-next-line @typescript-eslint/naming-convention +export const LogLevels = Object.values(LogLevel); + +export type LogHandler = (message: string, context?: LogData, error?: Error) => void; + +type LogDataBasic = string | number | bigint | boolean | null | undefined; +export type LogData = LogDataBasic | Record | LogDataBasic[] | Record[]; diff --git a/packages/utils/src/logger/index.ts b/packages/utils/src/logger/index.ts deleted file mode 100644 index 2212a1b6e61f..000000000000 --- a/packages/utils/src/logger/index.ts +++ /dev/null @@ -1,4 +0,0 @@ -export * from "./interface.js"; -export * from "./format.js"; -export * from "./winston.js"; -export {LogData} from "./json.js"; diff --git a/packages/validator/src/util/logger.ts b/packages/validator/src/util/logger.ts index 31238954e5ae..2df655645c40 100644 --- a/packages/validator/src/util/logger.ts +++ b/packages/validator/src/util/logger.ts @@ -2,7 +2,7 @@ import {ApiError} from "@lodestar/api"; import {LogData, Logger, isErrorAborted} from "@lodestar/utils"; import {IClock} from "./clock.js"; -export type LoggerVc = Pick & { +export type LoggerVc = Logger & { isSyncing(e: Error): void; }; @@ -35,6 +35,7 @@ export function getLoggerVc(logger: Logger, clock: IClock): LoggerVc { info: logger.info.bind(logger), verbose: logger.verbose.bind(logger), debug: logger.debug.bind(logger), + trace: logger.trace.bind(logger), /** * Throttle "node is syncing" errors to not pollute the console too much. diff --git a/packages/validator/test/utils/logger.ts b/packages/validator/test/utils/logger.ts index 4850ce3f5e0a..6077b23a9583 100644 --- a/packages/validator/test/utils/logger.ts +++ b/packages/validator/test/utils/logger.ts @@ -1,4 +1,4 @@ -import {createWinstonLogger, LogLevel, Logger} from "@lodestar/utils"; +import {getEnvLogger} from "@lodestar/logger/env"; import {getLoggerVc} from "../../src/util/index.js"; import {ClockMock} from "./clock.js"; @@ -10,15 +10,6 @@ import {ClockMock} from "./clock.js"; * VERBOSE=1 mocha .ts * ``` */ -export function testLogger(module?: string): Logger { - return createWinstonLogger({level: getLogLevel(), module}); -} +export const testLogger = getEnvLogger; -function getLogLevel(): LogLevel { - if (process.env["LOG_LEVEL"]) return process.env["LOG_LEVEL"] as LogLevel; - if (process.env["DEBUG"]) return LogLevel.debug; - if (process.env["VERBOSE"]) return LogLevel.verbose; - return LogLevel.error; -} - -export const loggerVc = getLoggerVc(testLogger(), new ClockMock()); +export const loggerVc = getLoggerVc(getEnvLogger(), new ClockMock());