From bead54d081b8b32996e6eb041f25e7e7075dfd3d Mon Sep 17 00:00:00 2001 From: dapplion <35266934+dapplion@users.noreply.github.com> Date: Fri, 12 May 2023 22:47:27 +0900 Subject: [PATCH 01/18] Add tests for logging in workers --- packages/cli/test/e2e/logger/workerLogger.ts | 19 +++++ .../test/e2e/logger/workerLoggerHandler.ts | 32 ++++++++ .../cli/test/e2e/logger/workerLogs.test.ts | 76 +++++++++++++++++++ 3 files changed, 127 insertions(+) create mode 100644 packages/cli/test/e2e/logger/workerLogger.ts create mode 100644 packages/cli/test/e2e/logger/workerLoggerHandler.ts create mode 100644 packages/cli/test/e2e/logger/workerLogs.test.ts diff --git a/packages/cli/test/e2e/logger/workerLogger.ts b/packages/cli/test/e2e/logger/workerLogger.ts new file mode 100644 index 000000000000..0a4f1dd9207b --- /dev/null +++ b/packages/cli/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/cli/test/e2e/logger/workerLoggerHandler.ts b/packages/cli/test/e2e/logger/workerLoggerHandler.ts new file mode 100644 index 000000000000..3ff095fc4f89 --- /dev/null +++ b/packages/cli/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/cli/test/e2e/logger/workerLogs.test.ts b/packages/cli/test/e2e/logger/workerLogs.test.ts new file mode 100644 index 000000000000..52b8b5efa4b1 --- /dev/null +++ b/packages/cli/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}`); +} From c3f6ea89cf470269e81778fd393f015e2dff7c5d Mon Sep 17 00:00:00 2001 From: dapplion <35266934+dapplion@users.noreply.github.com> Date: Sat, 13 May 2023 07:41:50 +0900 Subject: [PATCH 02/18] Add logger package --- packages/logger/.mocharc.yml | 3 + packages/logger/LICENSE | 201 ++++++++++++++++++ packages/logger/README.md | 12 ++ packages/logger/package.json | 66 ++++++ packages/logger/src/logger/format.ts | 93 ++++++++ packages/logger/src/logger/index.ts | 4 + packages/logger/src/logger/interface.ts | 65 ++++++ packages/logger/src/logger/json.ts | 127 +++++++++++ packages/logger/src/logger/util.ts | 15 ++ packages/logger/src/logger/winston.ts | 107 ++++++++++ .../src/node/consoleTransport.ts} | 0 .../logger.ts => logger/src/node/index.ts} | 42 ++-- .../test/e2e/logger/workerLogger.ts | 0 .../test/e2e/logger/workerLoggerHandler.ts | 0 .../test/e2e/logger/workerLogs.test.ts | 0 packages/logger/test/setup.ts | 6 + .../util => logger/test/unit}/logger.test.ts | 2 +- packages/logger/test/unit/logger/json.test.ts | 199 +++++++++++++++++ packages/logger/test/unit/logger/util.test.ts | 23 ++ .../logger/test/unit/logger/winston.test.ts | 107 ++++++++++ .../test/unit}/loggerTransport.test.ts | 0 packages/logger/test/utils/chai.ts | 9 + packages/logger/tsconfig.build.json | 7 + packages/logger/tsconfig.e2e.json | 7 + packages/logger/tsconfig.json | 4 + 25 files changed, 1072 insertions(+), 27 deletions(-) create mode 100644 packages/logger/.mocharc.yml create mode 100644 packages/logger/LICENSE create mode 100644 packages/logger/README.md create mode 100644 packages/logger/package.json create mode 100644 packages/logger/src/logger/format.ts create mode 100644 packages/logger/src/logger/index.ts create mode 100644 packages/logger/src/logger/interface.ts create mode 100644 packages/logger/src/logger/json.ts create mode 100644 packages/logger/src/logger/util.ts create mode 100644 packages/logger/src/logger/winston.ts rename packages/{cli/src/util/loggerConsoleTransport.ts => logger/src/node/consoleTransport.ts} (100%) rename packages/{cli/src/util/logger.ts => logger/src/node/index.ts} (86%) rename packages/{cli => logger}/test/e2e/logger/workerLogger.ts (100%) rename packages/{cli => logger}/test/e2e/logger/workerLoggerHandler.ts (100%) rename packages/{cli => logger}/test/e2e/logger/workerLogs.test.ts (100%) create mode 100644 packages/logger/test/setup.ts rename packages/{cli/test/unit/util => logger/test/unit}/logger.test.ts (95%) create mode 100644 packages/logger/test/unit/logger/json.test.ts create mode 100644 packages/logger/test/unit/logger/util.test.ts create mode 100644 packages/logger/test/unit/logger/winston.test.ts rename packages/{cli/test/unit/util => logger/test/unit}/loggerTransport.test.ts (100%) create mode 100644 packages/logger/test/utils/chai.ts create mode 100644 packages/logger/tsconfig.build.json create mode 100644 packages/logger/tsconfig.e2e.json create mode 100644 packages/logger/tsconfig.json 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..3f18c3536860 --- /dev/null +++ b/packages/logger/package.json @@ -0,0 +1,66 @@ +{ + "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" + }, + "./logger": { + "import": "./lib/logger/index.js" + }, + "./node": { + "import": "./lib/node/index.js" + } + }, + "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'", + "test:browsers": "yarn karma start karma.config.cjs", + "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" + }, + "keywords": [ + "ethereum", + "eth-consensus", + "beacon", + "blockchain" + ] +} diff --git a/packages/logger/src/logger/format.ts b/packages/logger/src/logger/format.ts new file mode 100644 index 000000000000..4f9aff995f3c --- /dev/null +++ b/packages/logger/src/logger/format.ts @@ -0,0 +1,93 @@ +import winston from "winston"; +import {logCtxToJson, logCtxToString, LogData} from "./json.js"; +import {LoggerOptions, TimestampFormatCode} from "./interface.js"; +import {formatEpochSlotTime} from "./util.js"; + +const {format} = winston; + +type Format = ReturnType; + +// TODO: Find a more typesafe way of enforce this properties +type WinstonInfoArg = { + level: string; + message: string; + module?: string; + namespace?: string; + timestamp: string; + context: LogData; + error: Error; +}; + +export function getFormat(opts: LoggerOptions): Format { + switch (opts.format) { + case "json": + return jsonLogFormat(opts); + + case "human": + default: + return humanReadableLogFormat(opts); + } +} + +function humanReadableLogFormat(opts: LoggerOptions): Format { + return format.combine( + ...(opts.hideTimestamp ? [] : [formatTimestamp(opts)]), + format.colorize(), + format.printf(humanReadableTemplateFn) + ); +} + +function formatTimestamp(opts: LoggerOptions): Format { + const {timestampFormat} = opts; + + switch (timestampFormat?.format) { + case TimestampFormatCode.EpochSlot: + return { + transform: (info) => { + info.timestamp = formatEpochSlotTime(timestampFormat); + return info; + }, + }; + + case TimestampFormatCode.DateRegular: + default: + return format.timestamp({format: "MMM-DD HH:mm:ss.SSS"}); + } +} + +function jsonLogFormat(opts: LoggerOptions): Format { + return format.combine( + ...(opts.hideTimestamp ? [] : [format.timestamp()]), + format((_info) => { + const info = _info as WinstonInfoArg; + info.context = logCtxToJson(info.context); + info.error = logCtxToJson(info.error) as unknown as Error; + return info; + })(), + format.json() + ); +} + +/** + * Winston template function print a human readable string given a log object + */ +// eslint-disable-next-line @typescript-eslint/no-explicit-any +function humanReadableTemplateFn(_info: {[key: string]: any; level: string; message: string}): string { + const info = _info as WinstonInfoArg; + + const paddingBetweenInfo = 30; + + const infoString = info.module || info.namespace || ""; + const infoPad = paddingBetweenInfo - infoString.length; + + let str = ""; + + if (info.timestamp) str += info.timestamp; + + str += `[${infoString}] ${info.level.padStart(infoPad)}: ${info.message}`; + + if (info.context !== undefined) str += " " + logCtxToString(info.context); + if (info.error !== undefined) str += " " + logCtxToString(info.error); + + return str; +} diff --git a/packages/logger/src/logger/index.ts b/packages/logger/src/logger/index.ts new file mode 100644 index 000000000000..2212a1b6e61f --- /dev/null +++ b/packages/logger/src/logger/index.ts @@ -0,0 +1,4 @@ +export * from "./interface.js"; +export * from "./format.js"; +export * from "./winston.js"; +export {LogData} from "./json.js"; diff --git a/packages/logger/src/logger/interface.ts b/packages/logger/src/logger/interface.ts new file mode 100644 index 000000000000..3c323feecdaa --- /dev/null +++ b/packages/logger/src/logger/interface.ts @@ -0,0 +1,65 @@ +import {LogData} from "./json.js"; + +export enum LogLevel { + error = "error", + warn = "warn", + info = "info", + verbose = "verbose", + debug = "debug", + trace = "trace", +} + +export const logLevelNum: {[K in LogLevel]: number} = { + [LogLevel.error]: 0, + [LogLevel.warn]: 1, + [LogLevel.info]: 2, + [LogLevel.verbose]: 3, + [LogLevel.debug]: 4, + /** Request in https://github.com/ChainSafe/lodestar/issues/4536 by eth-docker */ + [LogLevel.trace]: 5, +}; + +// 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"]; + +export type EpochSlotOpts = { + genesisTime: number; + secondsPerSlot: number; + slotsPerEpoch: number; +}; +export enum TimestampFormatCode { + DateRegular, + EpochSlot, +} +export type TimestampFormat = + | {format: TimestampFormatCode.DateRegular} + | ({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/logger/json.ts b/packages/logger/src/logger/json.ts new file mode 100644 index 000000000000..47c6807b99ed --- /dev/null +++ b/packages/logger/src/logger/json.ts @@ -0,0 +1,127 @@ +import {LodestarError, mapValues, toHexString} from "@lodestar/utils"; + +const MAX_DEPTH = 0; + +type LogDataBasic = string | number | bigint | boolean | null | undefined; + +export type LogData = LogDataBasic | Record | LogDataBasic[] | Record[]; + +/** + * Renders any log Context to JSON up to one level of depth. + * + * By limiting recursiveness, it renders limited content while ensuring safer logging. + * Consumers of the logger should ensure to send pre-formated data if they require nesting. + */ +export function logCtxToJson(arg: unknown, depth = 0, fromError = false): LogData { + switch (typeof arg) { + case "bigint": + case "symbol": + case "function": + return arg.toString(); + + case "object": + if (arg === null) return "null"; + + if (arg instanceof Uint8Array) { + return toHexString(arg); + } + + // For any type that may include recursiveness break early at the first level + // - Prevent recursive loops + // - Ensures Error with deep complex metadata won't leak into the logs and cause bugs + if (depth > MAX_DEPTH) { + return "[object]"; + } + + if (arg instanceof Error) { + let metadata: Record; + if (arg instanceof LodestarError) { + if (fromError) { + return "[LodestarErrorCircular]"; + } else { + // Allow one extra depth level for LodestarError + metadata = logCtxToJson(arg.getMetadata(), depth - 1, true) as Record; + } + } else { + metadata = {message: arg.message}; + } + if (arg.stack) metadata.stack = arg.stack; + return metadata as LogData; + } + + if (Array.isArray(arg)) { + return arg.map((item) => logCtxToJson(item, depth + 1)) as LogData; + } + + return mapValues(arg as Record, (item) => logCtxToJson(item, depth + 1)) as LogData; + + // Already valid JSON + case "number": + case "string": + case "undefined": + case "boolean": + return arg; + + default: + return String(arg); + } +} + +/** + * Renders any log Context to a string up to one level of depth. + * + * By limiting recursiveness, it renders limited content while ensuring safer logging. + * Consumers of the logger should ensure to send pre-formated data if they require nesting. + */ +export function logCtxToString(arg: unknown, depth = 0, fromError = false): string { + switch (typeof arg) { + case "bigint": + case "symbol": + case "function": + return arg.toString(); + + case "object": + if (arg === null) return "null"; + + if (arg instanceof Uint8Array) { + return toHexString(arg); + } + + // For any type that may include recursiveness break early at the first level + // - Prevent recursive loops + // - Ensures Error with deep complex metadata won't leak into the logs and cause bugs + if (depth > MAX_DEPTH) { + return "[object]"; + } + + if (arg instanceof Error) { + let metadata: string; + if (arg instanceof LodestarError) { + if (fromError) { + return "[LodestarErrorCircular]"; + } else { + // Allow one extra depth level for LodestarError + metadata = logCtxToString(arg.getMetadata(), depth - 1, true); + } + } else { + metadata = arg.message; + } + return `${metadata}\n${arg.stack || ""}`; + } + + if (Array.isArray(arg)) { + return arg.map((item) => logCtxToString(item, depth + 1)).join(", "); + } + + return Object.entries(arg) + .map(([key, value]) => `${key}=${logCtxToString(value, depth + 1)}`) + .join(", "); + + case "number": + case "string": + case "undefined": + case "boolean": + default: + return String(arg); + } +} diff --git a/packages/logger/src/logger/util.ts b/packages/logger/src/logger/util.ts new file mode 100644 index 000000000000..0e949db3b859 --- /dev/null +++ b/packages/logger/src/logger/util.ts @@ -0,0 +1,15 @@ +import {EpochSlotOpts} from "./interface.js"; + +/** + * Formats time as: `EPOCH/SLOT_INDEX SECONDS.MILLISECONDS + */ +export function formatEpochSlotTime(opts: EpochSlotOpts, now = Date.now()): string { + const nowSec = now / 1000; + const secSinceGenesis = nowSec - opts.genesisTime; + const epoch = Math.floor(secSinceGenesis / (opts.slotsPerEpoch * opts.secondsPerSlot)); + const epochStartSec = opts.genesisTime + epoch * opts.slotsPerEpoch * opts.secondsPerSlot; + const secSinceStartEpoch = nowSec - epochStartSec; + const slotIndex = Math.floor(secSinceStartEpoch / opts.secondsPerSlot); + const slotSec = secSinceStartEpoch % opts.secondsPerSlot; + return `Eph ${epoch}/${slotIndex} ${slotSec.toFixed(3)}`; +} diff --git a/packages/logger/src/logger/winston.ts b/packages/logger/src/logger/winston.ts new file mode 100644 index 000000000000..91e175a41600 --- /dev/null +++ b/packages/logger/src/logger/winston.ts @@ -0,0 +1,107 @@ +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"; + +// # How to configure Winston log level? +// +// - Log level is meant to be configured BY TRANSPORT only +// - There's no native logic that allows different logLevels by metadata.module +// - Transports are shared between child loggers, so a custom transport is required +// +// This is the logic that controls if log or not based on each log message level. +// Winston transport base class TransportStream check its own transport level to decide to format then log +// +// ```ts +// TransportStream.prototype._write = function _write(info, enc, callback) { +// const level = this.level || (this.parent && this.parent.level); +// if (!level || this.levels[level] >= this.levels[info[LEVEL]]) { +// transformed = this.format.transform(Object.assign({}, info), this.format.options); +// return this.log(transformed, callback); +// } +// }; +// ``` +// https://github.com/winstonjs/winston-transport/blob/51baf6138753f0766181355fb50b1b0334344c56/index.js#L80 +// +// To configure different logLevel per metadata.module the simplest solution is to have a custom Transport +// that overrides the `transport._write` with a lookup on a Map of module -> log level. This is done in +// the CLI package on a special ConsoleTransport that could be set dynamically. + +interface DefaultMeta { + module: string; +} + +export function createWinstonLogger(options: Partial = {}, transports?: winston.transport[]): Logger { + return WinstonLogger.fromOpts(options, transports); +} + +export class WinstonLogger implements Logger { + constructor(private readonly winston: Winston) {} + + static fromOpts(options: Partial = {}, transports?: winston.transport[]): WinstonLogger { + const defaultMeta: DefaultMeta = {module: options?.module || ""}; + + return new WinstonLogger( + winston.createLogger({ + // Do not set level at the logger level. Always control by Transport, unless for testLogger + level: options.level, + defaultMeta, + format: getFormat(options), + transports, + exitOnError: false, + levels: logLevelNum, + }) + ); + } + + error(message: string, context?: LogData, error?: Error): void { + this.createLogEntry(LogLevel.error, message, context, error); + } + + warn(message: string, context?: LogData, error?: Error): void { + this.createLogEntry(LogLevel.warn, message, context, error); + } + + info(message: string, context?: LogData, error?: Error): void { + this.createLogEntry(LogLevel.info, message, context, error); + } + + verbose(message: string, context?: LogData, error?: Error): void { + this.createLogEntry(LogLevel.verbose, message, context, error); + } + + debug(message: string, context?: LogData, error?: Error): void { + this.createLogEntry(LogLevel.debug, message, context, error); + } + + trace(message: string, context?: LogData, error?: Error): void { + 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 + + // If winston logger is called with `winston.info(message, context, error)` it triggers the "splat" path + // while we just need winston to forward an object to the custom formatter. So we call the fn signature below + // https://github.com/winstonjs/winston/blob/3f1dcc13cda384eb30fe3b941764e47a5a5efc26/lib/winston/logger.js#L221 + this.winston.log(level, {message, context, error}); + } +} diff --git a/packages/cli/src/util/loggerConsoleTransport.ts b/packages/logger/src/node/consoleTransport.ts similarity index 100% rename from packages/cli/src/util/loggerConsoleTransport.ts rename to packages/logger/src/node/consoleTransport.ts diff --git a/packages/cli/src/util/logger.ts b/packages/logger/src/node/index.ts similarity index 86% rename from packages/cli/src/util/logger.ts rename to packages/logger/src/node/index.ts index 9dac44e3782d..c093d5c568cb 100644 --- a/packages/cli/src/util/logger.ts +++ b/packages/logger/src/node/index.ts @@ -4,18 +4,8 @@ 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 {GlobalArgs} from "../options/globalOptions.js"; -import {ConsoleDynamicLevel} from "./loggerConsoleTransport.js"; +import {Logger, LogLevel, createWinstonLogger, TimestampFormat, LogFormat, logFormats} from "@lodestar/utils"; +import {ConsoleDynamicLevel} from "./consoleTransport.js"; export const LOG_FILE_DISABLE_KEYWORD = "none"; export const LOG_LEVEL_DEFAULT = LogLevel.info; @@ -32,13 +22,25 @@ export type LogArgs = { logPrefix?: string; logFormat?: string; logLevelModule?: string[]; + /** + * Enables relative to genesis timestamp format + * ``` + * { + * format: TimestampFormatCode.EpochSlot, + * genesisTime: args.logFormatGenesisTime, + * secondsPerSlot: config.SECONDS_PER_SLOT, + * slotsPerEpoch: SLOTS_PER_EPOCH, + * } + * ``` + */ + timestampFormat?: TimestampFormat; }; /** * Setup a CLI logger, common for beacon, validator and dev commands */ export function getCliLogger( - args: LogArgs & Pick, + args: LogArgs, paths: {defaultLogFilepath: string}, config: ChainForkConfig, opts?: {hideTimestamp?: boolean} @@ -96,23 +98,11 @@ export function getCliLogger( ); } - const timestampFormat: TimestampFormat = - args.logFormatGenesisTime !== undefined - ? { - format: TimestampFormatCode.EpochSlot, - genesisTime: args.logFormatGenesisTime, - secondsPerSlot: config.SECONDS_PER_SLOT, - slotsPerEpoch: SLOTS_PER_EPOCH, - } - : { - format: TimestampFormatCode.DateRegular, - }; - const logger = createWinstonLogger( { module: args.logPrefix, format: args.logFormat ? parseLogFormat(args.logFormat) : "human", - timestampFormat, + timestampFormat: args.timestampFormat, hideTimestamp: opts?.hideTimestamp, }, transports diff --git a/packages/cli/test/e2e/logger/workerLogger.ts b/packages/logger/test/e2e/logger/workerLogger.ts similarity index 100% rename from packages/cli/test/e2e/logger/workerLogger.ts rename to packages/logger/test/e2e/logger/workerLogger.ts diff --git a/packages/cli/test/e2e/logger/workerLoggerHandler.ts b/packages/logger/test/e2e/logger/workerLoggerHandler.ts similarity index 100% rename from packages/cli/test/e2e/logger/workerLoggerHandler.ts rename to packages/logger/test/e2e/logger/workerLoggerHandler.ts diff --git a/packages/cli/test/e2e/logger/workerLogs.test.ts b/packages/logger/test/e2e/logger/workerLogs.test.ts similarity index 100% rename from packages/cli/test/e2e/logger/workerLogs.test.ts rename to packages/logger/test/e2e/logger/workerLogs.test.ts 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/logger/test/unit/logger/json.test.ts b/packages/logger/test/unit/logger/json.test.ts new file mode 100644 index 000000000000..6b423de50d40 --- /dev/null +++ b/packages/logger/test/unit/logger/json.test.ts @@ -0,0 +1,199 @@ +/* eslint-disable @typescript-eslint/no-unsafe-member-access, @typescript-eslint/no-unsafe-assignment */ +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"; + +describe("Json helper", () => { + const circularReference = {}; + (circularReference as {myself: unknown}).myself = circularReference; + + describe("toJson", () => { + type TestCase = { + id: string; + arg: unknown; + json: any; + }; + const testCases: (TestCase | (() => TestCase))[] = [ + // Basic types + {id: "undefined", arg: undefined, json: undefined}, + {id: "null", arg: null, json: "null"}, + {id: "boolean", arg: true, json: true}, + {id: "number", arg: 123, json: 123}, + {id: "bigint", arg: BigInt(123), json: "123"}, + {id: "string", arg: "hello", json: "hello"}, + {id: "symbol", arg: Symbol("foo"), json: "Symbol(foo)"}, + + // Functions + // eslint-disable-next-line @typescript-eslint/no-empty-function + {id: "function", arg: function () {}, json: "function () { }"}, + // eslint-disable-next-line @typescript-eslint/no-empty-function + {id: "arrow function", arg: () => {}, json: "() => { }"}, + // eslint-disable-next-line @typescript-eslint/no-empty-function + {id: "async function", arg: async function () {}, json: "async function () { }"}, + // eslint-disable-next-line @typescript-eslint/no-empty-function + {id: "async arrow function", arg: async () => {}, json: "async () => { }"}, + + // Arrays + {id: "array of basic types", arg: [1, 2, 3], json: [1, 2, 3]}, + { + id: "array of arrays", + arg: [ + [1, 2], + [3, 4], + ], + json: ["[object]", "[object]"], + }, + + // Objects + {id: "object of basic types", arg: {a: 1, b: 2}, json: {a: 1, b: 2}}, + {id: "object of objects", arg: {a: {b: 1}}, json: {a: "[object]"}}, + () => { + const rootHex = "0x11111111111111111111111111111111"; + return { + id: "Object with Uint8Array prop", + arg: {root: fromHexString(rootHex)}, + json: {root: rootHex}, + }; + }, + + // Errors + () => { + const error = new Error("foo"); + return { + id: "Normal error", + arg: error, + json: { + message: error.message, + stack: error.stack, + }, + }; + }, + () => { + class SampleError extends Error { + data: string; + constructor(data: string) { + super("SAMPLE ERROR"); + this.data = data; + } + } + const data = "foo"; + const error = new SampleError(data); + return { + id: "External error with metadata (ignored)", + arg: error, + json: { + message: error.message, + stack: error.stack, + }, + }; + }, + () => { + const data = {code: "SOME_ERROR", foo: 123}; + const error = new LodestarError(data); + return { + id: "Lodestar error", + arg: error, + json: { + ...data, + stack: error.stack, + }, + }; + }, + () => { + const code = "ERR_PARENT_UNKNOWN"; + const rootHex = "0x11111111111111111111111111111111"; + const error = new LodestarError({code, root: fromHexString(rootHex)}); + return { + id: "Lodestar error with Uint8Array", + arg: error, + json: { + code, + root: rootHex, + stack: error.stack, + }, + }; + }, + + // Circular references + () => { + const circularReference: any = {}; + circularReference.myself = circularReference; + return { + id: "circular reference", + arg: circularReference, + json: {myself: "[object]"}, + }; + }, + ]; + + for (const testCase of testCases) { + const {id, arg, json} = typeof testCase === "function" ? testCase() : testCase; + it(id, () => { + expect(logCtxToJson(arg)).to.deep.equal(json); + }); + } + }); + + describe("toString", () => { + const root = new Uint8Array(32); + const rootHex = toHexString(root); + + type TestCase = { + id: string; + json: unknown; + output: string; + }; + const testCases: (TestCase | (() => TestCase))[] = [ + // Basic types + {id: "null", json: null, output: "null"}, + {id: "boolean", json: true, output: "true"}, + {id: "number", json: 123, output: "123"}, + {id: "string", json: "hello", output: "hello"}, + {id: "root", json: root, output: rootHex}, + + // Arrays + {id: "array of basic types", json: [1, 2, 3], output: "1, 2, 3"}, + { + id: "array of arrays", + json: [ + [1, 2], + [3, 4], + ], + output: "[object], [object]", + }, + + // Objects + {id: "object of basic types", json: {a: 1, b: "a", c: root}, output: `a=1, b=a, c=${rootHex}`}, + // eslint-disable-next-line quotes + {id: "object of objects", json: {a: {b: 1}}, output: `a=[object]`}, + { + id: "error metadata", + json: { + code: "ERR_PARENT_UNKNOWN", + parentRoot: "0x1111111111111111111111111111111111", + }, + output: "code=ERR_PARENT_UNKNOWN, parentRoot=0x1111111111111111111111111111111111", + }, + + // Circular references + () => { + const circularReference: any = {}; + circularReference.myself = circularReference; + return { + id: "circular reference", + json: circularReference, + output: "myself=[object]", + }; + }, + ]; + + for (const testCase of testCases) { + const {id, json, output} = typeof testCase === "function" ? testCase() : testCase; + it(id, () => { + expect(logCtxToString(json)).to.equal(output); + }); + } + }); +}); diff --git a/packages/logger/test/unit/logger/util.test.ts b/packages/logger/test/unit/logger/util.test.ts new file mode 100644 index 000000000000..2ceaa0613cc4 --- /dev/null +++ b/packages/logger/test/unit/logger/util.test.ts @@ -0,0 +1,23 @@ +import "../../setup.js"; +import {expect} from "chai"; +import {formatEpochSlotTime} from "../../../src/logger/util.js"; + +describe("logger / util / formatEpochSlotTime", () => { + const nowSec = 1619171569; + const secondsPerSlot = 12; + const slotsPerEpoch = 32; + + const testCases: {epoch: number; slot: number; sec: number}[] = [ + {epoch: 3, slot: 6, sec: 11.423}, + {epoch: -1, slot: 31, sec: 11.423}, + {epoch: 0, slot: 0, sec: 0.001}, + ]; + + for (const {epoch, slot, sec} of testCases) { + const expectLog = `Eph ${epoch}/${slot} ${sec}`; // "Eph 3/6 11.423"; + it(expectLog, () => { + const genesisTime = nowSec - epoch * slotsPerEpoch * secondsPerSlot - slot * secondsPerSlot - sec; + expect(formatEpochSlotTime({genesisTime, secondsPerSlot, slotsPerEpoch}, nowSec * 1000)).to.equal(expectLog); + }); + } +}); diff --git a/packages/logger/test/unit/logger/winston.test.ts b/packages/logger/test/unit/logger/winston.test.ts new file mode 100644 index 000000000000..7357bab39e4a --- /dev/null +++ b/packages/logger/test/unit/logger/winston.test.ts @@ -0,0 +1,107 @@ +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"; + +type WinstonLog = {[MESSAGE]: string}; + +class MemoryTransport extends Transport { + private readonly logs: WinstonLog[] = []; + + log(info: WinstonLog, next: () => void): void { + this.logs.push(info); + next(); + } + + getLogs(): string[] { + return this.logs.map((log) => log[MESSAGE]); + } +} + +// describe("winston logger log level logic", () => { +// it("Should not run format function for not used log level", () => { +// const logger = createWinstonLogger({format, hideTimestamp: true}, [new MemoryTransport()]); +// }); +// }); + +describe("winston logger", () => { + describe("winston logger format and options", () => { + type TestCase = { + id: string; + message: string; + context?: LogData; + error?: Error; + output: {[P in LogFormat]: string}; + }; + /* eslint-disable quotes */ + const testCases: (TestCase | (() => TestCase))[] = [ + { + id: "regular log with metadata", + message: "foo bar", + context: {meta: "data"}, + output: { + human: "[] \u001b[33mwarn\u001b[39m: foo bar meta=data", + json: `{"context":{"meta":"data"},"level":"warn","message":"foo bar","module":""}`, + }, + }, + + { + id: "regular log with big int metadata", + message: "big int", + context: {data: BigInt(1)}, + output: { + human: "[] \u001b[33mwarn\u001b[39m: big int data=1", + json: `{"context":{"data":"1"},"level":"warn","message":"big int","module":""}`, + }, + }, + + () => { + const error = new LodestarError({code: "SAMPLE_ERROR", data: {foo: "bar"}}); + error.stack = "$STACK"; + return { + id: "error with metadata", + opts: {format: "human", module: "SAMPLE"}, + message: "foo bar", + error: error, + output: { + human: `[] \u001b[33mwarn\u001b[39m: foo bar code=SAMPLE_ERROR, data=foo=bar\n${error.stack}`, + json: `{"error":{"code":"SAMPLE_ERROR","data":{"foo":"bar"},"stack":"$STACK"},"level":"warn","message":"foo bar","module":""}`, + }, + }; + }, + ]; + + for (const testCase of testCases) { + const {id, message, context, error, output} = typeof testCase === "function" ? testCase() : testCase; + for (const format of logFormats) { + it(`${id} ${format} output`, async () => { + const memoryTransport = new MemoryTransport(); + const logger = createWinstonLogger({format, hideTimestamp: true}, [memoryTransport]); + logger.warn(message, context, error); + + expect(memoryTransport.getLogs()).deep.equals([output[format]]); + }); + } + } + }); + + describe("child logger", () => { + it("Should parse child module", async () => { + const memoryTransport = new MemoryTransport(); + const loggerA = createWinstonLogger({hideTimestamp: true, module: "a"}, [memoryTransport]); + const loggerAB = loggerA.child({module: "b"}); + const loggerABC = loggerAB.child({module: "c"}); + + loggerA.warn("test a"); + loggerAB.warn("test a/b"); + loggerABC.warn("test a/b/c"); + + expect(memoryTransport.getLogs()).deep.equals([ + "[a] \u001b[33mwarn\u001b[39m: test a", + "[a/b] \u001b[33mwarn\u001b[39m: test a/b", + "[a/b/c] \u001b[33mwarn\u001b[39m: test a/b/c", + ]); + }); + }); +}); diff --git a/packages/cli/test/unit/util/loggerTransport.test.ts b/packages/logger/test/unit/loggerTransport.test.ts similarity index 100% rename from packages/cli/test/unit/util/loggerTransport.test.ts rename to packages/logger/test/unit/loggerTransport.test.ts 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": {} +} From c6c5295991827938d6cbb46af12c5fb0e89038fc Mon Sep 17 00:00:00 2001 From: dapplion <35266934+dapplion@users.noreply.github.com> Date: Sat, 13 May 2023 12:19:44 +0900 Subject: [PATCH 03/18] Implement multiple independent loggers --- packages/beacon-node/package.json | 1 + .../beacon-node/src/network/discv5/index.ts | 7 +- .../beacon-node/src/network/discv5/types.ts | 2 + .../beacon-node/src/network/discv5/worker.ts | 9 + packages/beacon-node/src/network/network.ts | 9 +- .../beacon-node/src/network/peers/discover.ts | 7 +- .../src/network/peers/peerManager.ts | 6 +- packages/beacon-node/src/node/nodejs.ts | 4 +- packages/cli/package.json | 1 + packages/cli/src/cmds/beacon/handler.ts | 14 +- packages/cli/src/cmds/beacon/options.ts | 4 +- packages/cli/src/cmds/lightclient/handler.ts | 7 +- packages/cli/src/cmds/lightclient/options.ts | 4 +- packages/cli/src/cmds/validator/handler.ts | 14 +- .../decryptKeystoreDefinitions/types.ts | 4 +- packages/cli/src/cmds/validator/options.ts | 4 +- .../cli/src/cmds/validator/signers/index.ts | 4 +- .../src/cmds/validator/signers/logSigners.ts | 4 +- .../validator/slashingProtection/export.ts | 10 +- .../validator/slashingProtection/import.ts | 10 +- packages/cli/src/options/logOptions.ts | 28 +-- packages/cli/src/util/logger.ts | 102 +++++++++++ packages/logger/src/browser.ts | 54 ++++++ packages/logger/src/empty.ts | 24 +++ packages/logger/src/index.ts | 5 + packages/logger/src/{logger => }/interface.ts | 33 +--- packages/logger/src/logger/format.ts | 8 +- packages/logger/src/logger/index.ts | 2 - packages/logger/src/logger/json.ts | 1 - .../src/logger/timeFormat.ts} | 2 +- packages/logger/src/logger/util.ts | 15 -- packages/logger/src/logger/winston.ts | 21 +-- packages/logger/src/node/consoleTransport.ts | 2 +- packages/logger/src/node/index.ts | 172 +++++++++--------- packages/logger/test/unit/logger/util.test.ts | 2 +- packages/prover/src/utils/logger.ts | 80 +------- packages/utils/src/index.ts | 2 +- packages/utils/src/logger.ts | 21 +++ packages/utils/src/logger/format.ts | 93 ---------- packages/utils/src/logger/index.ts | 4 - packages/utils/src/logger/interface.ts | 65 ------- packages/utils/src/logger/json.ts | 129 ------------- packages/utils/src/logger/winston.ts | 107 ----------- packages/validator/src/util/logger.ts | 3 +- 44 files changed, 408 insertions(+), 692 deletions(-) create mode 100644 packages/cli/src/util/logger.ts create mode 100644 packages/logger/src/browser.ts create mode 100644 packages/logger/src/empty.ts create mode 100644 packages/logger/src/index.ts rename packages/logger/src/{logger => }/interface.ts (62%) rename packages/{utils/src/logger/util.ts => logger/src/logger/timeFormat.ts} (93%) delete mode 100644 packages/logger/src/logger/util.ts create mode 100644 packages/utils/src/logger.ts delete mode 100644 packages/utils/src/logger/format.ts delete mode 100644 packages/utils/src/logger/index.ts delete mode 100644 packages/utils/src/logger/interface.ts delete mode 100644 packages/utils/src/logger/json.ts delete mode 100644 packages/utils/src/logger/winston.ts 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..4547b7409493 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"; 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..f4931097b4a5 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 {LogOpts} from "@lodestar/logger"; // 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: LogOpts; } /** diff --git a/packages/beacon-node/src/network/discv5/worker.ts b/packages/beacon-node/src/network/discv5/worker.ts index 5f2eba45bd62..94557e25c38c 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"; 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 9bc5b4955e65..b255faaa6310 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"; 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..a96c7b79d31e 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"; 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..d4212050bb41 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"; 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..8675e5b61f03 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"; 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/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..27f8b9627af9 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"; 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..126e649389ff 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"; 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..88f4589c4baf 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"; 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..e2012d6b78f9 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"; 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 new file mode 100644 index 000000000000..a4c4938f1eb5 --- /dev/null +++ b/packages/cli/src/util/logger.ts @@ -0,0 +1,102 @@ +import path from "node:path"; +import fs from "node:fs"; +import {ChainForkConfig} from "@lodestar/config"; +import {SLOTS_PER_EPOCH} from "@lodestar/params"; +import {LogFormat, LogOpts, TimestampFormatCode, logFormats} from "@lodestar/logger"; +import {LogLevel} from "@lodestar/utils"; +import {LogArgs} from "../options/logOptions.js"; +import {GlobalArgs} from "../options/globalOptions.js"; + +export const LOG_FILE_DISABLE_KEYWORD = "none"; + +/** + * Setup a CLI logger, common for beacon, validator and dev commands + */ +export function parseLoggerArgs( + args: LogArgs & Pick, + paths: {defaultLogFilepath: string}, + config: ChainForkConfig, + opts?: {hideTimestamp?: boolean} +): LogOpts { + 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, + }, + prefix: 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, + secondsPerSlot: config.SECONDS_PER_SLOT, + slotsPerEpoch: SLOTS_PER_EPOCH, + } + : { + format: TimestampFormatCode.DateRegular, + }, + }; +} + +function parseLogFormat(format: string): LogFormat { + if (!logFormats.includes(format as LogFormat)) { + throw Error(`Unknown log format ${format}`); + } + return format as LogFormat; +} + +function parseLogLevel(level: string): LogLevel { + if (LogLevel[level as LogLevel] === undefined) { + throw Error(`Unknown log level '${level}'`); + } + return level as LogLevel; +} + +function parseLogLevelModule(logLevelModuleArr: string[]): Record { + const levelModule: Record = {}; + for (const logLevelModule of logLevelModuleArr) { + const [module, levelStr] = logLevelModule.split("="); + levelModule[module] = parseLogLevel(levelStr); + } + return levelModule; +} + +/** + * Winston is not able to clean old log files if server is offline for a while + * so we have to do this manually when starting the node. + * See https://github.com/ChainSafe/lodestar/issues/4419 + */ +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); + const toDelete = fs + .readdirSync(folder, {withFileTypes: true}) + .filter((de) => de.isFile()) + .map((de) => de.name) + .filter((logFileName) => shouldDeleteLogFile(prefix, extension, logFileName, args.logFileDailyRotate)) + .map((logFileName) => path.join(folder, logFileName)); + // delete files + toDelete.forEach((filename) => fs.unlinkSync(filename)); +} + +export function shouldDeleteLogFile(prefix: string, extension: string, logFileName: string, maxFiles: number): boolean { + const maxDifferenceMs = maxFiles * 24 * 60 * 60 * 1000; + const match = logFileName.match(new RegExp(`${prefix}-([0-9]{4}-[0-9]{2}-[0-9]{2}).${extension}`)); + // if match[1] exists, it should be the date pattern of YYYY-MM-DD + if (match && match[1] && Date.now() - new Date(match[1]).getTime() > maxDifferenceMs) { + return true; + } + return false; +} diff --git a/packages/logger/src/browser.ts b/packages/logger/src/browser.ts new file mode 100644 index 000000000000..6727f315780a --- /dev/null +++ b/packages/logger/src/browser.ts @@ -0,0 +1,54 @@ +import winston from "winston"; +import Transport from "winston-transport"; +import {LogLevel, Logger} from "@lodestar/utils"; +import {createWinstonLogger} from "./logger/index.js"; + +export type BrowserLoggerOpts = { + level: LogLevel; +}; + +export function getBrowserLogger(opts: BrowserLoggerOpts): Logger { + return createWinstonLogger({level: opts.level, module: "prover"}, [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/index.ts b/packages/logger/src/index.ts new file mode 100644 index 000000000000..3be4063f7a4d --- /dev/null +++ b/packages/logger/src/index.ts @@ -0,0 +1,5 @@ +export * from "./logger/index.js"; +export * from "./node/index.js"; +export * from "./interface.js"; +export * from "./browser.js"; +export * from "./empty.js"; diff --git a/packages/logger/src/logger/interface.ts b/packages/logger/src/interface.ts similarity index 62% rename from packages/logger/src/logger/interface.ts rename to packages/logger/src/interface.ts index 3c323feecdaa..05e74a54b3d9 100644 --- a/packages/logger/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/logger/format.ts b/packages/logger/src/logger/format.ts index 4f9aff995f3c..18575b16e246 100644 --- a/packages/logger/src/logger/format.ts +++ b/packages/logger/src/logger/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/logger/src/logger/index.ts b/packages/logger/src/logger/index.ts index 2212a1b6e61f..7faea8da71cb 100644 --- a/packages/logger/src/logger/index.ts +++ b/packages/logger/src/logger/index.ts @@ -1,4 +1,2 @@ -export * from "./interface.js"; export * from "./format.js"; export * from "./winston.js"; -export {LogData} from "./json.js"; diff --git a/packages/logger/src/logger/json.ts b/packages/logger/src/logger/json.ts index 47c6807b99ed..fa4443be4ebd 100644 --- a/packages/logger/src/logger/json.ts +++ b/packages/logger/src/logger/json.ts @@ -3,7 +3,6 @@ import {LodestarError, mapValues, toHexString} from "@lodestar/utils"; const MAX_DEPTH = 0; type LogDataBasic = string | number | bigint | boolean | null | undefined; - export type LogData = LogDataBasic | Record | LogDataBasic[] | Record[]; /** diff --git a/packages/utils/src/logger/util.ts b/packages/logger/src/logger/timeFormat.ts similarity index 93% rename from packages/utils/src/logger/util.ts rename to packages/logger/src/logger/timeFormat.ts index 0e949db3b859..38ae0ee40ae8 100644 --- a/packages/utils/src/logger/util.ts +++ b/packages/logger/src/logger/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/logger/src/logger/util.ts b/packages/logger/src/logger/util.ts deleted file mode 100644 index 0e949db3b859..000000000000 --- a/packages/logger/src/logger/util.ts +++ /dev/null @@ -1,15 +0,0 @@ -import {EpochSlotOpts} from "./interface.js"; - -/** - * Formats time as: `EPOCH/SLOT_INDEX SECONDS.MILLISECONDS - */ -export function formatEpochSlotTime(opts: EpochSlotOpts, now = Date.now()): string { - const nowSec = now / 1000; - const secSinceGenesis = nowSec - opts.genesisTime; - const epoch = Math.floor(secSinceGenesis / (opts.slotsPerEpoch * opts.secondsPerSlot)); - const epochStartSec = opts.genesisTime + epoch * opts.slotsPerEpoch * opts.secondsPerSlot; - const secSinceStartEpoch = nowSec - epochStartSec; - const slotIndex = Math.floor(secSinceStartEpoch / opts.secondsPerSlot); - const slotSec = secSinceStartEpoch % opts.secondsPerSlot; - return `Eph ${epoch}/${slotIndex} ${slotSec.toFixed(3)}`; -} diff --git a/packages/logger/src/logger/winston.ts b/packages/logger/src/logger/winston.ts index 91e175a41600..75def6fa1051 100644 --- a/packages/logger/src/logger/winston.ts +++ b/packages/logger/src/logger/winston.ts @@ -1,6 +1,6 @@ import winston from "winston"; import type {Logger as Winston} from "winston"; -import {Logger, LoggerOptions, LoggerChildOpts, LogLevel, logLevelNum} from "./interface.js"; +import {Logger, LoggerOptions, LogLevel, logLevelNum} from "../interface.js"; import {getFormat} from "./format.js"; import {LogData} from "./json.js"; @@ -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/src/node/consoleTransport.ts b/packages/logger/src/node/consoleTransport.ts index 69ba70b54236..4a4ba3bcc4eb 100644 --- a/packages/logger/src/node/consoleTransport.ts +++ b/packages/logger/src/node/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/logger/src/node/index.ts b/packages/logger/src/node/index.ts index c093d5c568cb..6b63b6a89173 100644 --- a/packages/logger/src/node/index.ts +++ b/packages/logger/src/node/index.ts @@ -1,31 +1,45 @@ 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 {Logger, LogLevel, createWinstonLogger, TimestampFormat, LogFormat, logFormats} from "@lodestar/utils"; +import {Logger, LogLevel, logLevelNum, TimestampFormat} from "../interface.js"; +import {getFormat, WinstonLogger} from "../logger/index.js"; import {ConsoleDynamicLevel} from "./consoleTransport.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[]; +export type LogOpts = { + 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 + */ + prefix?: 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, @@ -36,30 +50,32 @@ export type LogArgs = { timestampFormat?: TimestampFormat; }; +export type LoggerNodeChildOpts = { + module?: string; +}; + +export type LoggerNode = Logger & { + toOpts(): LogOpts; + child(opts: LoggerNodeChildOpts): LoggerNode; +}; + /** * Setup a CLI logger, common for beacon, validator and dev commands */ -export function getCliLogger( - args: LogArgs, - paths: {defaultLogFilepath: string}, - config: ChainForkConfig, - opts?: {hideTimestamp?: boolean} -): {logger: Logger; logParams: {filename: string; rotateMaxFiles: number}} { +export function getNodeLogger(opts: LogOpts): LoggerNode { + return WinstonLoggerNode.fromNewTransports(opts); +} + +function getNodeLoggerTransports(opts: LogOpts): winston.transport[] { const consoleTransport = new ConsoleDynamicLevel({ // Set defaultLevel, not level for dynamic level setting of ConsoleDynamicLvevel - defaultLevel: args.logLevel ?? LOG_LEVEL_DEFAULT, + defaultLevel: opts.level, 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}'`); - } - + if (opts.levelModule) { + for (const [module, level] of Object.entries(opts.levelModule)) { consoleTransport.setModuleLevel(module, level); } } @@ -74,78 +90,70 @@ export function getCliLogger( // `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; + if (opts.file) { + const filename = opts.file.filepath; transports.push( - rotateMaxFiles > 0 + opts.file.dailyRotate != null ? new DailyRotateFile({ - level: logFileLevel, + level: opts.file.level, //insert the date pattern in filename before the file extension. filename: filename.replace(/\.(?=[^.]*$)|$/, "-%DATE%$&"), datePattern: DATE_PATTERN, handleExceptions: true, - maxFiles: rotateMaxFiles, + maxFiles: opts.file.dailyRotate, auditFile: path.join(path.dirname(filename), ".log_rotate_audit.json"), }) : new winston.transports.File({ - level: logFileLevel, + level: opts.file.level, filename: filename, handleExceptions: true, }) ); } - const logger = createWinstonLogger( - { - module: args.logPrefix, - format: args.logFormat ? parseLogFormat(args.logFormat) : "human", - timestampFormat: args.timestampFormat, - hideTimestamp: opts?.hideTimestamp, - }, - transports - ); - - return {logger, logParams: {filename, rotateMaxFiles}}; + return transports; } -/** - * Winston is not able to clean old log files if server is offline for a while - * 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); - const lastIndexDot = filename.lastIndexOf("."); - const prefix = filename.substring(0, lastIndexDot); - const extension = filename.substring(lastIndexDot + 1, filename.length); - const toDelete = fs - .readdirSync(folder, {withFileTypes: true}) - .filter((de) => de.isFile()) - .map((de) => de.name) - .filter((logFileName) => shouldDeleteLogFile(prefix, extension, logFileName, maxFiles)) - .map((logFileName) => path.join(folder, logFileName)); - // delete files - toDelete.forEach((filename) => fs.unlinkSync(filename)); +interface DefaultMeta { + module: string; } -export function shouldDeleteLogFile(prefix: string, extension: string, logFileName: string, maxFiles: number): boolean { - const maxDifferenceMs = maxFiles * 24 * 60 * 60 * 1000; - const match = logFileName.match(new RegExp(`${prefix}-([0-9]{4}-[0-9]{2}-[0-9]{2}).${extension}`)); - // if match[1] exists, it should be the date pattern of YYYY-MM-DD - if (match && match[1] && Date.now() - new Date(match[1]).getTime() > maxDifferenceMs) { - return true; +export class WinstonLoggerNode extends WinstonLogger implements LoggerNode { + constructor(private readonly opts: LogOpts, private readonly transports: winston.transport[]) { + const defaultMeta: DefaultMeta = {module: opts?.prefix || ""}; + 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: LogOpts): WinstonLoggerNode { + return new WinstonLoggerNode(opts, getNodeLoggerTransports(opts)); } - return false; -} -function parseLogFormat(format: string): LogFormat { - if (!logFormats.includes(format as LogFormat)) { - throw Error(`Invalid log format '${format}'`); + // 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 { + const childModule = [this.opts?.prefix, opts.module].filter(Boolean).join("/"); + + const childOpts: LogOpts = { + ...this.opts, + prefix: childModule, + }; + + return new WinstonLoggerNode(childOpts, this.transports); } - return format as LogFormat; + toOpts(): LogOpts { + return this.opts; + } } diff --git a/packages/logger/test/unit/logger/util.test.ts b/packages/logger/test/unit/logger/util.test.ts index 2ceaa0613cc4..5537e3d7a68f 100644 --- a/packages/logger/test/unit/logger/util.test.ts +++ b/packages/logger/test/unit/logger/util.test.ts @@ -1,6 +1,6 @@ import "../../setup.js"; import {expect} from "chai"; -import {formatEpochSlotTime} from "../../../src/logger/util.js"; +import {formatEpochSlotTime} from "../../../src/logger/timeFormat.js"; describe("logger / util / formatEpochSlotTime", () => { const nowSec = 1619171569; diff --git a/packages/prover/src/utils/logger.ts b/packages/prover/src/utils/logger.ts index 9035993833b2..80702d9bdf60 100644 --- a/packages/prover/src/utils/logger.ts +++ b/packages/prover/src/utils/logger.ts @@ -1,87 +1,21 @@ -import winston from "winston"; -import Transport from "winston-transport"; -import {LogData, Logger, LoggerChildOpts, createWinstonLogger} from "@lodestar/utils"; +import {Logger} from "@lodestar/utils"; +import {getNodeLogger, getBrowserLogger, getEmptyLogger} from "@lodestar/logger"; 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()]); + // TODO for @nazarhussain: Any issue with pulling this code into the Web3Provider path? + // Can we just use the console.log logger for all code paths? + return getNodeLogger({level: opts.logLevel}); } if (opts.logLevel && process === undefined) { - return createWinstonLogger({level: opts.logLevel, module: "prover"}, [new BrowserConsole({level: 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/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/format.ts b/packages/utils/src/logger/format.ts deleted file mode 100644 index 4f9aff995f3c..000000000000 --- a/packages/utils/src/logger/format.ts +++ /dev/null @@ -1,93 +0,0 @@ -import winston from "winston"; -import {logCtxToJson, logCtxToString, LogData} from "./json.js"; -import {LoggerOptions, TimestampFormatCode} from "./interface.js"; -import {formatEpochSlotTime} from "./util.js"; - -const {format} = winston; - -type Format = ReturnType; - -// TODO: Find a more typesafe way of enforce this properties -type WinstonInfoArg = { - level: string; - message: string; - module?: string; - namespace?: string; - timestamp: string; - context: LogData; - error: Error; -}; - -export function getFormat(opts: LoggerOptions): Format { - switch (opts.format) { - case "json": - return jsonLogFormat(opts); - - case "human": - default: - return humanReadableLogFormat(opts); - } -} - -function humanReadableLogFormat(opts: LoggerOptions): Format { - return format.combine( - ...(opts.hideTimestamp ? [] : [formatTimestamp(opts)]), - format.colorize(), - format.printf(humanReadableTemplateFn) - ); -} - -function formatTimestamp(opts: LoggerOptions): Format { - const {timestampFormat} = opts; - - switch (timestampFormat?.format) { - case TimestampFormatCode.EpochSlot: - return { - transform: (info) => { - info.timestamp = formatEpochSlotTime(timestampFormat); - return info; - }, - }; - - case TimestampFormatCode.DateRegular: - default: - return format.timestamp({format: "MMM-DD HH:mm:ss.SSS"}); - } -} - -function jsonLogFormat(opts: LoggerOptions): Format { - return format.combine( - ...(opts.hideTimestamp ? [] : [format.timestamp()]), - format((_info) => { - const info = _info as WinstonInfoArg; - info.context = logCtxToJson(info.context); - info.error = logCtxToJson(info.error) as unknown as Error; - return info; - })(), - format.json() - ); -} - -/** - * Winston template function print a human readable string given a log object - */ -// eslint-disable-next-line @typescript-eslint/no-explicit-any -function humanReadableTemplateFn(_info: {[key: string]: any; level: string; message: string}): string { - const info = _info as WinstonInfoArg; - - const paddingBetweenInfo = 30; - - const infoString = info.module || info.namespace || ""; - const infoPad = paddingBetweenInfo - infoString.length; - - let str = ""; - - if (info.timestamp) str += info.timestamp; - - str += `[${infoString}] ${info.level.padStart(infoPad)}: ${info.message}`; - - if (info.context !== undefined) str += " " + logCtxToString(info.context); - if (info.error !== undefined) str += " " + logCtxToString(info.error); - - return str; -} 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/utils/src/logger/interface.ts b/packages/utils/src/logger/interface.ts deleted file mode 100644 index 3c323feecdaa..000000000000 --- a/packages/utils/src/logger/interface.ts +++ /dev/null @@ -1,65 +0,0 @@ -import {LogData} from "./json.js"; - -export enum LogLevel { - error = "error", - warn = "warn", - info = "info", - verbose = "verbose", - debug = "debug", - trace = "trace", -} - -export const logLevelNum: {[K in LogLevel]: number} = { - [LogLevel.error]: 0, - [LogLevel.warn]: 1, - [LogLevel.info]: 2, - [LogLevel.verbose]: 3, - [LogLevel.debug]: 4, - /** Request in https://github.com/ChainSafe/lodestar/issues/4536 by eth-docker */ - [LogLevel.trace]: 5, -}; - -// 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"]; - -export type EpochSlotOpts = { - genesisTime: number; - secondsPerSlot: number; - slotsPerEpoch: number; -}; -export enum TimestampFormatCode { - DateRegular, - EpochSlot, -} -export type TimestampFormat = - | {format: TimestampFormatCode.DateRegular} - | ({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/utils/src/logger/json.ts b/packages/utils/src/logger/json.ts deleted file mode 100644 index d0ea3c3123ef..000000000000 --- a/packages/utils/src/logger/json.ts +++ /dev/null @@ -1,129 +0,0 @@ -import {toHexString} from "../bytes.js"; -import {LodestarError} from "../errors.js"; -import {mapValues} from "../objects.js"; - -const MAX_DEPTH = 0; - -type LogDataBasic = string | number | bigint | boolean | null | undefined; - -export type LogData = LogDataBasic | Record | LogDataBasic[] | Record[]; - -/** - * Renders any log Context to JSON up to one level of depth. - * - * By limiting recursiveness, it renders limited content while ensuring safer logging. - * Consumers of the logger should ensure to send pre-formated data if they require nesting. - */ -export function logCtxToJson(arg: unknown, depth = 0, fromError = false): LogData { - switch (typeof arg) { - case "bigint": - case "symbol": - case "function": - return arg.toString(); - - case "object": - if (arg === null) return "null"; - - if (arg instanceof Uint8Array) { - return toHexString(arg); - } - - // For any type that may include recursiveness break early at the first level - // - Prevent recursive loops - // - Ensures Error with deep complex metadata won't leak into the logs and cause bugs - if (depth > MAX_DEPTH) { - return "[object]"; - } - - if (arg instanceof Error) { - let metadata: Record; - if (arg instanceof LodestarError) { - if (fromError) { - return "[LodestarErrorCircular]"; - } else { - // Allow one extra depth level for LodestarError - metadata = logCtxToJson(arg.getMetadata(), depth - 1, true) as Record; - } - } else { - metadata = {message: arg.message}; - } - if (arg.stack) metadata.stack = arg.stack; - return metadata as LogData; - } - - if (Array.isArray(arg)) { - return arg.map((item) => logCtxToJson(item, depth + 1)) as LogData; - } - - return mapValues(arg as Record, (item) => logCtxToJson(item, depth + 1)) as LogData; - - // Already valid JSON - case "number": - case "string": - case "undefined": - case "boolean": - return arg; - - default: - return String(arg); - } -} - -/** - * Renders any log Context to a string up to one level of depth. - * - * By limiting recursiveness, it renders limited content while ensuring safer logging. - * Consumers of the logger should ensure to send pre-formated data if they require nesting. - */ -export function logCtxToString(arg: unknown, depth = 0, fromError = false): string { - switch (typeof arg) { - case "bigint": - case "symbol": - case "function": - return arg.toString(); - - case "object": - if (arg === null) return "null"; - - if (arg instanceof Uint8Array) { - return toHexString(arg); - } - - // For any type that may include recursiveness break early at the first level - // - Prevent recursive loops - // - Ensures Error with deep complex metadata won't leak into the logs and cause bugs - if (depth > MAX_DEPTH) { - return "[object]"; - } - - if (arg instanceof Error) { - let metadata: string; - if (arg instanceof LodestarError) { - if (fromError) { - return "[LodestarErrorCircular]"; - } else { - // Allow one extra depth level for LodestarError - metadata = logCtxToString(arg.getMetadata(), depth - 1, true); - } - } else { - metadata = arg.message; - } - return `${metadata}\n${arg.stack || ""}`; - } - - if (Array.isArray(arg)) { - return arg.map((item) => logCtxToString(item, depth + 1)).join(", "); - } - - return Object.entries(arg) - .map(([key, value]) => `${key}=${logCtxToString(value, depth + 1)}`) - .join(", "); - - case "number": - case "string": - case "undefined": - case "boolean": - default: - return String(arg); - } -} diff --git a/packages/utils/src/logger/winston.ts b/packages/utils/src/logger/winston.ts deleted file mode 100644 index 91e175a41600..000000000000 --- a/packages/utils/src/logger/winston.ts +++ /dev/null @@ -1,107 +0,0 @@ -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"; - -// # How to configure Winston log level? -// -// - Log level is meant to be configured BY TRANSPORT only -// - There's no native logic that allows different logLevels by metadata.module -// - Transports are shared between child loggers, so a custom transport is required -// -// This is the logic that controls if log or not based on each log message level. -// Winston transport base class TransportStream check its own transport level to decide to format then log -// -// ```ts -// TransportStream.prototype._write = function _write(info, enc, callback) { -// const level = this.level || (this.parent && this.parent.level); -// if (!level || this.levels[level] >= this.levels[info[LEVEL]]) { -// transformed = this.format.transform(Object.assign({}, info), this.format.options); -// return this.log(transformed, callback); -// } -// }; -// ``` -// https://github.com/winstonjs/winston-transport/blob/51baf6138753f0766181355fb50b1b0334344c56/index.js#L80 -// -// To configure different logLevel per metadata.module the simplest solution is to have a custom Transport -// that overrides the `transport._write` with a lookup on a Map of module -> log level. This is done in -// the CLI package on a special ConsoleTransport that could be set dynamically. - -interface DefaultMeta { - module: string; -} - -export function createWinstonLogger(options: Partial = {}, transports?: winston.transport[]): Logger { - return WinstonLogger.fromOpts(options, transports); -} - -export class WinstonLogger implements Logger { - constructor(private readonly winston: Winston) {} - - static fromOpts(options: Partial = {}, transports?: winston.transport[]): WinstonLogger { - const defaultMeta: DefaultMeta = {module: options?.module || ""}; - - return new WinstonLogger( - winston.createLogger({ - // Do not set level at the logger level. Always control by Transport, unless for testLogger - level: options.level, - defaultMeta, - format: getFormat(options), - transports, - exitOnError: false, - levels: logLevelNum, - }) - ); - } - - error(message: string, context?: LogData, error?: Error): void { - this.createLogEntry(LogLevel.error, message, context, error); - } - - warn(message: string, context?: LogData, error?: Error): void { - this.createLogEntry(LogLevel.warn, message, context, error); - } - - info(message: string, context?: LogData, error?: Error): void { - this.createLogEntry(LogLevel.info, message, context, error); - } - - verbose(message: string, context?: LogData, error?: Error): void { - this.createLogEntry(LogLevel.verbose, message, context, error); - } - - debug(message: string, context?: LogData, error?: Error): void { - this.createLogEntry(LogLevel.debug, message, context, error); - } - - trace(message: string, context?: LogData, error?: Error): void { - 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 - - // If winston logger is called with `winston.info(message, context, error)` it triggers the "splat" path - // while we just need winston to forward an object to the custom formatter. So we call the fn signature below - // https://github.com/winstonjs/winston/blob/3f1dcc13cda384eb30fe3b941764e47a5a5efc26/lib/winston/logger.js#L221 - this.winston.log(level, {message, context, error}); - } -} 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. From 4e0d816b18e055c3c308869530bf11dbcc30ad01 Mon Sep 17 00:00:00 2001 From: dapplion <35266934+dapplion@users.noreply.github.com> Date: Sat, 13 May 2023 12:54:15 +0900 Subject: [PATCH 04/18] Fix tests --- .../beacon-node/src/network/discv5/types.ts | 4 +- packages/beacon-node/test/utils/logger.ts | 33 +-- packages/cli/src/util/logger.ts | 6 +- packages/cli/test/utils.ts | 4 +- packages/db/package.json | 3 + .../db/test/unit/controller/level.test.ts | 4 +- packages/db/test/utils/logger.ts | 20 -- packages/logger/package.json | 3 +- packages/logger/src/env.ts | 42 ++++ packages/logger/src/index.ts | 1 + packages/logger/src/node/index.ts | 33 ++- packages/logger/test/unit/logger/json.test.ts | 2 +- .../{util.test.ts => timeFormat.test.ts} | 0 .../logger/test/unit/logger/winston.test.ts | 13 +- .../logger/test/unit/loggerTransport.test.ts | 39 ++-- packages/prover/package.json | 1 + packages/prover/test/mocks/logger_mock.ts | 11 - .../prover/test/unit/utils/execution.test.ts | 18 +- .../verified_requests/eth_getBalance.test.ts | 5 +- .../eth_getBlockByHash.test.ts | 5 +- .../eth_getBlockByNumber.test.ts | 5 +- .../verified_requests/eth_getCode.test.ts | 5 +- .../eth_getTransactionCount.test.ts | 5 +- packages/reqresp/package.json | 1 + packages/reqresp/test/mocks/logger.ts | 11 - packages/reqresp/test/unit/ReqResp.test.ts | 4 +- .../reqresp/test/unit/request/index.test.ts | 7 +- .../reqresp/test/unit/response/index.test.ts | 7 +- .../test/perf/misc/arrayCreation.test.ts | 6 +- .../test/perf/misc/bitopts.test.ts | 5 +- packages/state-transition/test/perf/util.ts | 11 - .../state-transition/test/utils/logger.ts | 5 - packages/utils/test/unit/logger/json.test.ts | 199 ------------------ packages/utils/test/unit/logger/util.test.ts | 23 -- .../utils/test/unit/logger/winston.test.ts | 107 ---------- 35 files changed, 151 insertions(+), 497 deletions(-) delete mode 100644 packages/db/test/utils/logger.ts create mode 100644 packages/logger/src/env.ts rename packages/logger/test/unit/logger/{util.test.ts => timeFormat.test.ts} (100%) delete mode 100644 packages/prover/test/mocks/logger_mock.ts delete mode 100644 packages/reqresp/test/mocks/logger.ts delete mode 100644 packages/state-transition/test/utils/logger.ts delete mode 100644 packages/utils/test/unit/logger/json.test.ts delete mode 100644 packages/utils/test/unit/logger/util.test.ts delete mode 100644 packages/utils/test/unit/logger/winston.test.ts diff --git a/packages/beacon-node/src/network/discv5/types.ts b/packages/beacon-node/src/network/discv5/types.ts index f4931097b4a5..7f43a35bb044 100644 --- a/packages/beacon-node/src/network/discv5/types.ts +++ b/packages/beacon-node/src/network/discv5/types.ts @@ -1,7 +1,7 @@ import {Discv5, ENRData, SignableENRData} from "@chainsafe/discv5"; import {Observable} from "@chainsafe/threads/observable"; import {ChainConfig} from "@lodestar/config"; -import {LogOpts} from "@lodestar/logger"; +import {LoggerNodeOpts} from "@lodestar/logger"; // TODO export IDiscv5Config so we don't need this convoluted type type Discv5Config = Parameters<(typeof Discv5)["create"]>[0]["config"]; @@ -23,7 +23,7 @@ export interface Discv5WorkerData { metrics: boolean; chainConfig: ChainConfig; genesisValidatorsRoot: Uint8Array; - loggerOpts: LogOpts; + loggerOpts: LoggerNodeOpts; } /** diff --git a/packages/beacon-node/test/utils/logger.ts b/packages/beacon-node/test/utils/logger.ts index c068d1ba9a6b..702d5acc0eb2 100644 --- a/packages/beacon-node/test/utils/logger.ts +++ b/packages/beacon-node/test/utils/logger.ts @@ -1,12 +1,8 @@ -import winston from "winston"; -import {createWinstonLogger, Logger, LogLevel, TimestampFormat} from "@lodestar/utils"; +import {LogLevel} from "@lodestar/utils"; +import {getEnvLogger, LoggerEnvOpts} from "@lodestar/logger"; export {LogLevel}; -export type TestLoggerOpts = { - logLevel?: LogLevel; - logFile?: string; - timestampFormat?: TimestampFormat; -}; +export type TestLoggerOpts = LoggerEnvOpts; /** * Run the test with ENVs to control log level: @@ -16,25 +12,4 @@ 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, - }) - ); - } - - 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; -} +export const testLogger = getEnvLogger; diff --git a/packages/cli/src/util/logger.ts b/packages/cli/src/util/logger.ts index a4c4938f1eb5..4d5a8e2bd5bb 100644 --- a/packages/cli/src/util/logger.ts +++ b/packages/cli/src/util/logger.ts @@ -2,7 +2,7 @@ import path from "node:path"; import fs from "node:fs"; import {ChainForkConfig} from "@lodestar/config"; import {SLOTS_PER_EPOCH} from "@lodestar/params"; -import {LogFormat, LogOpts, TimestampFormatCode, logFormats} from "@lodestar/logger"; +import {LogFormat, LoggerNodeOpts, TimestampFormatCode, logFormats} from "@lodestar/logger"; import {LogLevel} from "@lodestar/utils"; import {LogArgs} from "../options/logOptions.js"; import {GlobalArgs} from "../options/globalOptions.js"; @@ -17,7 +17,7 @@ export function parseLoggerArgs( paths: {defaultLogFilepath: string}, config: ChainForkConfig, opts?: {hideTimestamp?: boolean} -): LogOpts { +): LoggerNodeOpts { return { level: parseLogLevel(args.logLevel), file: @@ -28,7 +28,7 @@ export function parseLoggerArgs( level: parseLogLevel(args.logFileLevel), dailyRotate: args.logFileDailyRotate, }, - prefix: args.logPrefix, + module: args.logPrefix, format: args.logFormat ? parseLogFormat(args.logFormat) : undefined, levelModule: args.logLevelModule && parseLogLevelModule(args.logLevelModule), timestampFormat: opts?.hideTimestamp diff --git a/packages/cli/test/utils.ts b/packages/cli/test/utils.ts index 991aabe958ec..62805bd47290 100644 --- a/packages/cli/test/utils.ts +++ b/packages/cli/test/utils.ts @@ -1,14 +1,14 @@ import fs from "node:fs"; import path from "node:path"; import tmp from "tmp"; -import {createWinstonLogger, Logger} from "@lodestar/utils"; +import {getEnvLogger} from "@lodestar/logger"; export const networkDev = "dev"; const tmpDir = tmp.dirSync({unsafeCleanup: true}); export const testFilesDir = tmpDir.name; -export const testLogger = (): Logger => createWinstonLogger(); +export const testLogger = getEnvLogger; 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..2a3c9c25f1b0 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"; 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/package.json b/packages/logger/package.json index 3f18c3536860..d707adaf86b3 100644 --- a/packages/logger/package.json +++ b/packages/logger/package.json @@ -55,7 +55,8 @@ }, "devDependencies": { "@types/triple-beam": "^1.3.2", - "triple-beam": "^1.3.0" + "triple-beam": "^1.3.0", + "rimraf": "^4.4.1" }, "keywords": [ "ethereum", diff --git a/packages/logger/src/env.ts b/packages/logger/src/env.ts new file mode 100644 index 000000000000..cf271aaeaeb8 --- /dev/null +++ b/packages/logger/src/env.ts @@ -0,0 +1,42 @@ +import winston from "winston"; +import {Logger, LogLevel} from "@lodestar/utils"; +import {TimestampFormat} from "./interface.js"; +import {createWinstonLogger} from "./logger/winston.js"; +export {LogLevel}; + +export type LoggerEnvOpts = { + logLevel?: LogLevel; + logFile?: string; + timestampFormat?: TimestampFormat; +}; + +/** + * Run the test with ENVs to control log level: + * ``` + * LOG_LEVEL=debug mocha .ts + * DEBUG=1 mocha .ts + * VERBOSE=1 mocha .ts + * ``` + */ +export function getEnvLogger(module?: string, opts?: LoggerEnvOpts): 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, + }) + ); + } + + 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; +} diff --git a/packages/logger/src/index.ts b/packages/logger/src/index.ts index 3be4063f7a4d..557fc74397ac 100644 --- a/packages/logger/src/index.ts +++ b/packages/logger/src/index.ts @@ -3,3 +3,4 @@ export * from "./node/index.js"; export * from "./interface.js"; export * from "./browser.js"; export * from "./empty.js"; +export * from "./env.js"; diff --git a/packages/logger/src/node/index.ts b/packages/logger/src/node/index.ts index 6b63b6a89173..e786f3e3fec9 100644 --- a/packages/logger/src/node/index.ts +++ b/packages/logger/src/node/index.ts @@ -8,7 +8,7 @@ import {ConsoleDynamicLevel} from "./consoleTransport.js"; const DATE_PATTERN = "YYYY-MM-DD"; -export type LogOpts = { +export type LoggerNodeOpts = { level: LogLevel; /** * Enable file output transport if set @@ -27,7 +27,7 @@ export type LogOpts = { /** * Module prefix for all logs */ - prefix?: string; + module?: string; /** * Rendering format for logs, defaults to "human" */ @@ -55,18 +55,18 @@ export type LoggerNodeChildOpts = { }; export type LoggerNode = Logger & { - toOpts(): LogOpts; + toOpts(): LoggerNodeOpts; child(opts: LoggerNodeChildOpts): LoggerNode; }; /** * Setup a CLI logger, common for beacon, validator and dev commands */ -export function getNodeLogger(opts: LogOpts): LoggerNode { +export function getNodeLogger(opts: LoggerNodeOpts): LoggerNode { return WinstonLoggerNode.fromNewTransports(opts); } -function getNodeLoggerTransports(opts: LogOpts): winston.transport[] { +function getNodeLoggerTransports(opts: LoggerNodeOpts): winston.transport[] { const consoleTransport = new ConsoleDynamicLevel({ // Set defaultLevel, not level for dynamic level setting of ConsoleDynamicLvevel defaultLevel: opts.level, @@ -120,8 +120,8 @@ interface DefaultMeta { } export class WinstonLoggerNode extends WinstonLogger implements LoggerNode { - constructor(private readonly opts: LogOpts, private readonly transports: winston.transport[]) { - const defaultMeta: DefaultMeta = {module: opts?.prefix || ""}; + 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 @@ -135,7 +135,7 @@ export class WinstonLoggerNode extends WinstonLogger implements LoggerNode { ); } - static fromNewTransports(opts: LogOpts): WinstonLoggerNode { + static fromNewTransports(opts: LoggerNodeOpts): WinstonLoggerNode { return new WinstonLoggerNode(opts, getNodeLoggerTransports(opts)); } @@ -143,17 +143,16 @@ export class WinstonLoggerNode extends WinstonLogger implements LoggerNode { // but a reference to the same transports, such that there's only one // transport instance per tree of child loggers child(opts: LoggerNodeChildOpts): LoggerNode { - const childModule = [this.opts?.prefix, opts.module].filter(Boolean).join("/"); - - const childOpts: LogOpts = { - ...this.opts, - prefix: childModule, - }; - - return new WinstonLoggerNode(childOpts, this.transports); + return new WinstonLoggerNode( + { + ...this.opts, + module: [this.opts?.module, opts.module].filter(Boolean).join("/"), + }, + this.transports + ); } - toOpts(): LogOpts { + toOpts(): LoggerNodeOpts { return this.opts; } } diff --git a/packages/logger/test/unit/logger/json.test.ts b/packages/logger/test/unit/logger/json.test.ts index 6b423de50d40..42571fc34ffe 100644 --- a/packages/logger/test/unit/logger/json.test.ts +++ b/packages/logger/test/unit/logger/json.test.ts @@ -2,7 +2,7 @@ import "../../setup.js"; import {expect} from "chai"; import {fromHexString, toHexString} from "@chainsafe/ssz"; -import {LodestarError} from "../../../src/index.js"; +import {LodestarError} from "@lodestar/utils"; import {logCtxToJson, logCtxToString} from "../../../src/logger/json.js"; describe("Json helper", () => { diff --git a/packages/logger/test/unit/logger/util.test.ts b/packages/logger/test/unit/logger/timeFormat.test.ts similarity index 100% rename from packages/logger/test/unit/logger/util.test.ts rename to packages/logger/test/unit/logger/timeFormat.test.ts diff --git a/packages/logger/test/unit/logger/winston.test.ts b/packages/logger/test/unit/logger/winston.test.ts index 7357bab39e4a..4726e3daed7a 100644 --- a/packages/logger/test/unit/logger/winston.test.ts +++ b/packages/logger/test/unit/logger/winston.test.ts @@ -2,7 +2,8 @@ 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, WinstonLoggerNode} from "../../../src/index.js"; type WinstonLog = {[MESSAGE]: string}; @@ -77,7 +78,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 +93,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/logger/test/unit/loggerTransport.test.ts b/packages/logger/test/unit/loggerTransport.test.ts index 73e31fbaf64d..163aea7d8120 100644 --- a/packages/logger/test/unit/loggerTransport.test.ts +++ b/packages/logger/test/unit/loggerTransport.test.ts @@ -1,10 +1,15 @@ 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, + LoggerNodeOpts, + LoggerNode, + TimestampFormatCode, + getNodeLogger, + logFormats, +} from "../../src/index.js"; describe("winston logger format and options", () => { type TestCase = { @@ -61,7 +66,7 @@ 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}); logger.warn(message, context, error); @@ -80,7 +85,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 +129,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 +144,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/prover/package.json b/packages/prover/package.json index 46ac00e4a4b7..df0d92bd1603 100644 --- a/packages/prover/package.json +++ b/packages/prover/package.json @@ -77,6 +77,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/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/unit/utils/execution.test.ts b/packages/prover/test/unit/utils/execution.test.ts index c4f2b78636be..332cebe47c7d 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"; import {ELProof, ELStorageProof} from "../../../src/types.js"; import {isValidAccount, isValidStorageKeys} from "../../../src/utils/verification.js"; import {invalidStorageProof, validStorageProof} from "../../fixtures/index.js"; -import {createMockLogger} from "../../mocks/logger_mock.js"; import eoaProof from "../../fixtures/sepolia/eth_getBalance_eoa_proof.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/prover/test/unit/verified_requests/eth_getBalance.test.ts b/packages/prover/test/unit/verified_requests/eth_getBalance.test.ts index e1fdb3164600..a680acd68910 100644 --- a/packages/prover/test/unit/verified_requests/eth_getBalance.test.ts +++ b/packages/prover/test/unit/verified_requests/eth_getBalance.test.ts @@ -4,14 +4,15 @@ import deepmerge from "deepmerge"; import {createForkConfig} from "@lodestar/config"; import {NetworkName, networksChainConfig} from "@lodestar/config/networks"; import {Logger} from "@lodestar/utils"; +import {getEnvLogger} from "@lodestar/logger"; import {UNVERIFIED_RESPONSE_CODE} from "../../../src/constants.js"; import {ELVerifiedRequestHandlerOpts} from "../../../src/interfaces.js"; import {eth_getBalance} from "../../../src/verified_requests/eth_getBalance.js"; import eth_getBalance_eoa from "../../fixtures/sepolia/eth_getBalance_eoa_proof.json" assert {type: "json"}; import eth_getBalance_contract from "../../fixtures/sepolia/eth_getBalance_contract_proof.json" assert {type: "json"}; -import {createMockLogger} from "../../mocks/logger_mock.js"; const testCases = [eth_getBalance_eoa, eth_getBalance_contract]; +const logger = getEnvLogger(); describe("verified_requests / eth_getBalance", () => { let options: {handler: sinon.SinonStub; logger: Logger; proofProvider: {getExecutionPayload: sinon.SinonStub}}; @@ -19,7 +20,7 @@ describe("verified_requests / eth_getBalance", () => { beforeEach(() => { options = { handler: sinon.stub(), - logger: createMockLogger(), + logger, proofProvider: {getExecutionPayload: sinon.stub()}, }; }); diff --git a/packages/prover/test/unit/verified_requests/eth_getBlockByHash.test.ts b/packages/prover/test/unit/verified_requests/eth_getBlockByHash.test.ts index 92a8846d9ff5..7409c0f3c9e6 100644 --- a/packages/prover/test/unit/verified_requests/eth_getBlockByHash.test.ts +++ b/packages/prover/test/unit/verified_requests/eth_getBlockByHash.test.ts @@ -4,23 +4,24 @@ import deepmerge from "deepmerge"; import {createForkConfig} from "@lodestar/config"; import {NetworkName, networksChainConfig} from "@lodestar/config/networks"; import {Logger} from "@lodestar/utils"; +import {getEnvLogger} from "@lodestar/logger"; import {UNVERIFIED_RESPONSE_CODE} from "../../../src/constants.js"; import {ELVerifiedRequestHandlerOpts} from "../../../src/interfaces.js"; import {ELBlock} from "../../../src/types.js"; import {eth_getBlockByHash} from "../../../src/verified_requests/eth_getBlockByHash.js"; import eth_getBlock_with_contractCreation from "../../fixtures/sepolia/eth_getBlock_with_contractCreation.json" assert {type: "json"}; import eth_getBlock_with_no_accessList from "../../fixtures/sepolia/eth_getBlock_with_no_accessList.json" assert {type: "json"}; -import {createMockLogger} from "../../mocks/logger_mock.js"; const testCases = [eth_getBlock_with_no_accessList, eth_getBlock_with_contractCreation]; describe("verified_requests / eth_getBlockByHash", () => { + const logger = getEnvLogger(); let options: {handler: sinon.SinonStub; logger: Logger; proofProvider: {getExecutionPayload: sinon.SinonStub}}; beforeEach(() => { options = { handler: sinon.stub(), - logger: createMockLogger(), + logger, proofProvider: {getExecutionPayload: sinon.stub()}, }; }); diff --git a/packages/prover/test/unit/verified_requests/eth_getBlockByNumber.test.ts b/packages/prover/test/unit/verified_requests/eth_getBlockByNumber.test.ts index 1217681c8b5a..80035394eb54 100644 --- a/packages/prover/test/unit/verified_requests/eth_getBlockByNumber.test.ts +++ b/packages/prover/test/unit/verified_requests/eth_getBlockByNumber.test.ts @@ -4,23 +4,24 @@ import deepmerge from "deepmerge"; import {createForkConfig} from "@lodestar/config"; import {NetworkName, networksChainConfig} from "@lodestar/config/networks"; import {Logger} from "@lodestar/utils"; +import {getEnvLogger} from "@lodestar/logger"; import {UNVERIFIED_RESPONSE_CODE} from "../../../src/constants.js"; import {ELVerifiedRequestHandlerOpts} from "../../../src/interfaces.js"; import {ELBlock} from "../../../src/types.js"; import eth_getBlock_with_contractCreation from "../../fixtures/sepolia/eth_getBlock_with_contractCreation.json" assert {type: "json"}; import eth_getBlock_with_no_accessList from "../../fixtures/sepolia/eth_getBlock_with_no_accessList.json" assert {type: "json"}; -import {createMockLogger} from "../../mocks/logger_mock.js"; import {eth_getBlockByNumber} from "../../../src/verified_requests/eth_getBlockByNumber.js"; const testCases = [eth_getBlock_with_no_accessList, eth_getBlock_with_contractCreation]; describe("verified_requests / eth_getBlockByNumber", () => { + const logger = getEnvLogger(); let options: {handler: sinon.SinonStub; logger: Logger; proofProvider: {getExecutionPayload: sinon.SinonStub}}; beforeEach(() => { options = { handler: sinon.stub(), - logger: createMockLogger(), + logger, proofProvider: {getExecutionPayload: sinon.stub()}, }; }); diff --git a/packages/prover/test/unit/verified_requests/eth_getCode.test.ts b/packages/prover/test/unit/verified_requests/eth_getCode.test.ts index a2d7671622a5..24da0a0343bb 100644 --- a/packages/prover/test/unit/verified_requests/eth_getCode.test.ts +++ b/packages/prover/test/unit/verified_requests/eth_getCode.test.ts @@ -4,22 +4,23 @@ import deepmerge from "deepmerge"; import {createForkConfig} from "@lodestar/config"; import {NetworkName, networksChainConfig} from "@lodestar/config/networks"; import {Logger} from "@lodestar/utils"; +import {getEnvLogger} from "@lodestar/logger"; import {UNVERIFIED_RESPONSE_CODE} from "../../../src/constants.js"; import {ELVerifiedRequestHandlerOpts} from "../../../src/interfaces.js"; import {eth_getCode} from "../../../src/verified_requests/eth_getCode.js"; import eth_getCodeCase1 from "../../fixtures/sepolia/eth_getCode.json" assert {type: "json"}; import ethContractProof from "../../fixtures/sepolia/eth_getBalance_contract_proof.json" assert {type: "json"}; -import {createMockLogger} from "../../mocks/logger_mock.js"; const testCases = [eth_getCodeCase1]; describe("verified_requests / eth_getCode", () => { + const logger = getEnvLogger(); let options: {handler: sinon.SinonStub; logger: Logger; proofProvider: {getExecutionPayload: sinon.SinonStub}}; beforeEach(() => { options = { handler: sinon.stub(), - logger: createMockLogger(), + logger, proofProvider: {getExecutionPayload: sinon.stub()}, }; }); diff --git a/packages/prover/test/unit/verified_requests/eth_getTransactionCount.test.ts b/packages/prover/test/unit/verified_requests/eth_getTransactionCount.test.ts index 4619a2fbbf96..a0ed03e0923a 100644 --- a/packages/prover/test/unit/verified_requests/eth_getTransactionCount.test.ts +++ b/packages/prover/test/unit/verified_requests/eth_getTransactionCount.test.ts @@ -4,22 +4,23 @@ import deepmerge from "deepmerge"; import {createForkConfig} from "@lodestar/config"; import {NetworkName, networksChainConfig} from "@lodestar/config/networks"; import {Logger} from "@lodestar/utils"; +import {getEnvLogger} from "@lodestar/logger"; import {UNVERIFIED_RESPONSE_CODE} from "../../../src/constants.js"; import {ELVerifiedRequestHandlerOpts} from "../../../src/interfaces.js"; import eth_getBalance_eoa from "../../fixtures/sepolia/eth_getBalance_eoa_proof.json" assert {type: "json"}; import eth_getBalance_contract from "../../fixtures/sepolia/eth_getBalance_contract_proof.json" assert {type: "json"}; -import {createMockLogger} from "../../mocks/logger_mock.js"; import {eth_getTransactionCount} from "../../../src/verified_requests/eth_getTransactionCount.js"; const testCases = [eth_getBalance_eoa, eth_getBalance_contract]; describe("verified_requests / eth_getTransactionCount", () => { + const logger = getEnvLogger(); let options: {handler: sinon.SinonStub; logger: Logger; proofProvider: {getExecutionPayload: sinon.SinonStub}}; beforeEach(() => { options = { handler: sinon.stub(), - logger: createMockLogger(), + logger, proofProvider: {getExecutionPayload: sinon.stub()}, }; }); 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..4891b3c55c42 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"; 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..602fd5b8174f 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"; +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..08cb912af9cb 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"; 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/test/unit/logger/json.test.ts b/packages/utils/test/unit/logger/json.test.ts deleted file mode 100644 index 6b423de50d40..000000000000 --- a/packages/utils/test/unit/logger/json.test.ts +++ /dev/null @@ -1,199 +0,0 @@ -/* eslint-disable @typescript-eslint/no-unsafe-member-access, @typescript-eslint/no-unsafe-assignment */ -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"; - -describe("Json helper", () => { - const circularReference = {}; - (circularReference as {myself: unknown}).myself = circularReference; - - describe("toJson", () => { - type TestCase = { - id: string; - arg: unknown; - json: any; - }; - const testCases: (TestCase | (() => TestCase))[] = [ - // Basic types - {id: "undefined", arg: undefined, json: undefined}, - {id: "null", arg: null, json: "null"}, - {id: "boolean", arg: true, json: true}, - {id: "number", arg: 123, json: 123}, - {id: "bigint", arg: BigInt(123), json: "123"}, - {id: "string", arg: "hello", json: "hello"}, - {id: "symbol", arg: Symbol("foo"), json: "Symbol(foo)"}, - - // Functions - // eslint-disable-next-line @typescript-eslint/no-empty-function - {id: "function", arg: function () {}, json: "function () { }"}, - // eslint-disable-next-line @typescript-eslint/no-empty-function - {id: "arrow function", arg: () => {}, json: "() => { }"}, - // eslint-disable-next-line @typescript-eslint/no-empty-function - {id: "async function", arg: async function () {}, json: "async function () { }"}, - // eslint-disable-next-line @typescript-eslint/no-empty-function - {id: "async arrow function", arg: async () => {}, json: "async () => { }"}, - - // Arrays - {id: "array of basic types", arg: [1, 2, 3], json: [1, 2, 3]}, - { - id: "array of arrays", - arg: [ - [1, 2], - [3, 4], - ], - json: ["[object]", "[object]"], - }, - - // Objects - {id: "object of basic types", arg: {a: 1, b: 2}, json: {a: 1, b: 2}}, - {id: "object of objects", arg: {a: {b: 1}}, json: {a: "[object]"}}, - () => { - const rootHex = "0x11111111111111111111111111111111"; - return { - id: "Object with Uint8Array prop", - arg: {root: fromHexString(rootHex)}, - json: {root: rootHex}, - }; - }, - - // Errors - () => { - const error = new Error("foo"); - return { - id: "Normal error", - arg: error, - json: { - message: error.message, - stack: error.stack, - }, - }; - }, - () => { - class SampleError extends Error { - data: string; - constructor(data: string) { - super("SAMPLE ERROR"); - this.data = data; - } - } - const data = "foo"; - const error = new SampleError(data); - return { - id: "External error with metadata (ignored)", - arg: error, - json: { - message: error.message, - stack: error.stack, - }, - }; - }, - () => { - const data = {code: "SOME_ERROR", foo: 123}; - const error = new LodestarError(data); - return { - id: "Lodestar error", - arg: error, - json: { - ...data, - stack: error.stack, - }, - }; - }, - () => { - const code = "ERR_PARENT_UNKNOWN"; - const rootHex = "0x11111111111111111111111111111111"; - const error = new LodestarError({code, root: fromHexString(rootHex)}); - return { - id: "Lodestar error with Uint8Array", - arg: error, - json: { - code, - root: rootHex, - stack: error.stack, - }, - }; - }, - - // Circular references - () => { - const circularReference: any = {}; - circularReference.myself = circularReference; - return { - id: "circular reference", - arg: circularReference, - json: {myself: "[object]"}, - }; - }, - ]; - - for (const testCase of testCases) { - const {id, arg, json} = typeof testCase === "function" ? testCase() : testCase; - it(id, () => { - expect(logCtxToJson(arg)).to.deep.equal(json); - }); - } - }); - - describe("toString", () => { - const root = new Uint8Array(32); - const rootHex = toHexString(root); - - type TestCase = { - id: string; - json: unknown; - output: string; - }; - const testCases: (TestCase | (() => TestCase))[] = [ - // Basic types - {id: "null", json: null, output: "null"}, - {id: "boolean", json: true, output: "true"}, - {id: "number", json: 123, output: "123"}, - {id: "string", json: "hello", output: "hello"}, - {id: "root", json: root, output: rootHex}, - - // Arrays - {id: "array of basic types", json: [1, 2, 3], output: "1, 2, 3"}, - { - id: "array of arrays", - json: [ - [1, 2], - [3, 4], - ], - output: "[object], [object]", - }, - - // Objects - {id: "object of basic types", json: {a: 1, b: "a", c: root}, output: `a=1, b=a, c=${rootHex}`}, - // eslint-disable-next-line quotes - {id: "object of objects", json: {a: {b: 1}}, output: `a=[object]`}, - { - id: "error metadata", - json: { - code: "ERR_PARENT_UNKNOWN", - parentRoot: "0x1111111111111111111111111111111111", - }, - output: "code=ERR_PARENT_UNKNOWN, parentRoot=0x1111111111111111111111111111111111", - }, - - // Circular references - () => { - const circularReference: any = {}; - circularReference.myself = circularReference; - return { - id: "circular reference", - json: circularReference, - output: "myself=[object]", - }; - }, - ]; - - for (const testCase of testCases) { - const {id, json, output} = typeof testCase === "function" ? testCase() : testCase; - it(id, () => { - expect(logCtxToString(json)).to.equal(output); - }); - } - }); -}); diff --git a/packages/utils/test/unit/logger/util.test.ts b/packages/utils/test/unit/logger/util.test.ts deleted file mode 100644 index 2ceaa0613cc4..000000000000 --- a/packages/utils/test/unit/logger/util.test.ts +++ /dev/null @@ -1,23 +0,0 @@ -import "../../setup.js"; -import {expect} from "chai"; -import {formatEpochSlotTime} from "../../../src/logger/util.js"; - -describe("logger / util / formatEpochSlotTime", () => { - const nowSec = 1619171569; - const secondsPerSlot = 12; - const slotsPerEpoch = 32; - - const testCases: {epoch: number; slot: number; sec: number}[] = [ - {epoch: 3, slot: 6, sec: 11.423}, - {epoch: -1, slot: 31, sec: 11.423}, - {epoch: 0, slot: 0, sec: 0.001}, - ]; - - for (const {epoch, slot, sec} of testCases) { - const expectLog = `Eph ${epoch}/${slot} ${sec}`; // "Eph 3/6 11.423"; - it(expectLog, () => { - const genesisTime = nowSec - epoch * slotsPerEpoch * secondsPerSlot - slot * secondsPerSlot - sec; - expect(formatEpochSlotTime({genesisTime, secondsPerSlot, slotsPerEpoch}, nowSec * 1000)).to.equal(expectLog); - }); - } -}); diff --git a/packages/utils/test/unit/logger/winston.test.ts b/packages/utils/test/unit/logger/winston.test.ts deleted file mode 100644 index 7357bab39e4a..000000000000 --- a/packages/utils/test/unit/logger/winston.test.ts +++ /dev/null @@ -1,107 +0,0 @@ -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"; - -type WinstonLog = {[MESSAGE]: string}; - -class MemoryTransport extends Transport { - private readonly logs: WinstonLog[] = []; - - log(info: WinstonLog, next: () => void): void { - this.logs.push(info); - next(); - } - - getLogs(): string[] { - return this.logs.map((log) => log[MESSAGE]); - } -} - -// describe("winston logger log level logic", () => { -// it("Should not run format function for not used log level", () => { -// const logger = createWinstonLogger({format, hideTimestamp: true}, [new MemoryTransport()]); -// }); -// }); - -describe("winston logger", () => { - describe("winston logger format and options", () => { - type TestCase = { - id: string; - message: string; - context?: LogData; - error?: Error; - output: {[P in LogFormat]: string}; - }; - /* eslint-disable quotes */ - const testCases: (TestCase | (() => TestCase))[] = [ - { - id: "regular log with metadata", - message: "foo bar", - context: {meta: "data"}, - output: { - human: "[] \u001b[33mwarn\u001b[39m: foo bar meta=data", - json: `{"context":{"meta":"data"},"level":"warn","message":"foo bar","module":""}`, - }, - }, - - { - id: "regular log with big int metadata", - message: "big int", - context: {data: BigInt(1)}, - output: { - human: "[] \u001b[33mwarn\u001b[39m: big int data=1", - json: `{"context":{"data":"1"},"level":"warn","message":"big int","module":""}`, - }, - }, - - () => { - const error = new LodestarError({code: "SAMPLE_ERROR", data: {foo: "bar"}}); - error.stack = "$STACK"; - return { - id: "error with metadata", - opts: {format: "human", module: "SAMPLE"}, - message: "foo bar", - error: error, - output: { - human: `[] \u001b[33mwarn\u001b[39m: foo bar code=SAMPLE_ERROR, data=foo=bar\n${error.stack}`, - json: `{"error":{"code":"SAMPLE_ERROR","data":{"foo":"bar"},"stack":"$STACK"},"level":"warn","message":"foo bar","module":""}`, - }, - }; - }, - ]; - - for (const testCase of testCases) { - const {id, message, context, error, output} = typeof testCase === "function" ? testCase() : testCase; - for (const format of logFormats) { - it(`${id} ${format} output`, async () => { - const memoryTransport = new MemoryTransport(); - const logger = createWinstonLogger({format, hideTimestamp: true}, [memoryTransport]); - logger.warn(message, context, error); - - expect(memoryTransport.getLogs()).deep.equals([output[format]]); - }); - } - } - }); - - describe("child logger", () => { - it("Should parse child module", async () => { - const memoryTransport = new MemoryTransport(); - const loggerA = createWinstonLogger({hideTimestamp: true, module: "a"}, [memoryTransport]); - const loggerAB = loggerA.child({module: "b"}); - const loggerABC = loggerAB.child({module: "c"}); - - loggerA.warn("test a"); - loggerAB.warn("test a/b"); - loggerABC.warn("test a/b/c"); - - expect(memoryTransport.getLogs()).deep.equals([ - "[a] \u001b[33mwarn\u001b[39m: test a", - "[a/b] \u001b[33mwarn\u001b[39m: test a/b", - "[a/b/c] \u001b[33mwarn\u001b[39m: test a/b/c", - ]); - }); - }); -}); From 0f37a613f901629f0c654024cc3f5de616c578c8 Mon Sep 17 00:00:00 2001 From: dapplion <35266934+dapplion@users.noreply.github.com> Date: Sun, 14 May 2023 10:57:33 +0900 Subject: [PATCH 05/18] Fix tests --- .../beacon-node/test/sim/merge-interop.test.ts | 3 ++- packages/logger/package.json | 1 - packages/validator/test/utils/logger.ts | 15 +++------------ 3 files changed, 5 insertions(+), 14 deletions(-) diff --git a/packages/beacon-node/test/sim/merge-interop.test.ts b/packages/beacon-node/test/sim/merge-interop.test.ts index 7cbe493c909e..adb368257395 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"; diff --git a/packages/logger/package.json b/packages/logger/package.json index d707adaf86b3..1f862dfa3902 100644 --- a/packages/logger/package.json +++ b/packages/logger/package.json @@ -43,7 +43,6 @@ "lint:fix": "yarn run lint --fix", "pretest": "yarn run check-types", "test:unit": "mocha 'test/**/*.test.ts'", - "test:browsers": "yarn karma start karma.config.cjs", "check-readme": "typescript-docs-verifier" }, "types": "lib/index.d.ts", diff --git a/packages/validator/test/utils/logger.ts b/packages/validator/test/utils/logger.ts index 4850ce3f5e0a..3f46e6f8dfbf 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"; 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()); From 934bf58684040da4eb5510f35ecc5772235e170f Mon Sep 17 00:00:00 2001 From: dapplion <35266934+dapplion@users.noreply.github.com> Date: Sun, 14 May 2023 11:15:18 +0900 Subject: [PATCH 06/18] Use separate exports in logger --- .../beacon-node/src/network/discv5/index.ts | 3 +- .../beacon-node/src/network/discv5/types.ts | 2 +- .../beacon-node/src/network/discv5/worker.ts | 2 +- packages/beacon-node/src/network/network.ts | 2 +- .../beacon-node/src/network/peers/discover.ts | 2 +- .../src/network/peers/peerManager.ts | 2 +- packages/beacon-node/src/node/nodejs.ts | 2 +- packages/logger/package.json | 9 ++-- packages/logger/src/env.ts | 42 ------------------- packages/logger/src/index.ts | 15 ++++--- packages/logger/src/logger/index.ts | 2 - packages/logger/src/{ => loggers}/browser.ts | 2 +- packages/logger/src/{ => loggers}/empty.ts | 0 .../src/{node/index.ts => loggers/node.ts} | 5 ++- .../logger/src/{logger => loggers}/winston.ts | 4 +- .../src/{node => utils}/consoleTransport.ts | 0 .../logger/src/{logger => utils}/format.ts | 0 packages/logger/src/{logger => utils}/json.ts | 0 .../src/{logger => utils}/timeFormat.ts | 0 packages/logger/test/unit/logger/json.test.ts | 2 +- .../test/unit/logger/timeFormat.test.ts | 2 +- .../logger/test/unit/logger/winston.test.ts | 3 +- .../logger/test/unit/loggerTransport.test.ts | 10 +---- packages/prover/src/utils/logger.ts | 4 +- 24 files changed, 39 insertions(+), 76 deletions(-) delete mode 100644 packages/logger/src/env.ts delete mode 100644 packages/logger/src/logger/index.ts rename packages/logger/src/{ => loggers}/browser.ts (96%) rename packages/logger/src/{ => loggers}/empty.ts (100%) rename packages/logger/src/{node/index.ts => loggers/node.ts} (96%) rename packages/logger/src/{logger => loggers}/winston.ts (97%) rename packages/logger/src/{node => utils}/consoleTransport.ts (100%) rename packages/logger/src/{logger => utils}/format.ts (100%) rename packages/logger/src/{logger => utils}/json.ts (100%) rename packages/logger/src/{logger => utils}/timeFormat.ts (100%) diff --git a/packages/beacon-node/src/network/discv5/index.ts b/packages/beacon-node/src/network/discv5/index.ts index 4547b7409493..3dc1ede715ee 100644 --- a/packages/beacon-node/src/network/discv5/index.ts +++ b/packages/beacon-node/src/network/discv5/index.ts @@ -5,7 +5,7 @@ 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 {LoggerNode} from "@lodestar/logger"; +import {LoggerNode} from "@lodestar/logger/node"; import {NetworkCoreMetrics} from "../core/metrics.js"; import {Discv5WorkerApi, Discv5WorkerData, LodestarDiscv5Opts} from "./types.js"; @@ -20,6 +20,7 @@ export type Discv5Opts = { export type Discv5Events = { discovered: (enr: ENR) => void; }; +src / utils / logger.ts; type Discv5WorkerStatus = | {status: "stopped"} diff --git a/packages/beacon-node/src/network/discv5/types.ts b/packages/beacon-node/src/network/discv5/types.ts index 7f43a35bb044..5630ed17a667 100644 --- a/packages/beacon-node/src/network/discv5/types.ts +++ b/packages/beacon-node/src/network/discv5/types.ts @@ -1,7 +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"; +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"]; diff --git a/packages/beacon-node/src/network/discv5/worker.ts b/packages/beacon-node/src/network/discv5/worker.ts index 94557e25c38c..e54ff2abb805 100644 --- a/packages/beacon-node/src/network/discv5/worker.ts +++ b/packages/beacon-node/src/network/discv5/worker.ts @@ -6,7 +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"; +import {getNodeLogger} from "@lodestar/logger/node"; import {RegistryMetricCreator} from "../../metrics/index.js"; import {collectNodeJSMetrics} from "../../metrics/nodeJsMetrics.js"; import {ENRKey} from "../metadata.js"; diff --git a/packages/beacon-node/src/network/network.ts b/packages/beacon-node/src/network/network.ts index b255faaa6310..dfeea854c9f0 100644 --- a/packages/beacon-node/src/network/network.ts +++ b/packages/beacon-node/src/network/network.ts @@ -4,7 +4,7 @@ import {Multiaddr} from "@multiformats/multiaddr"; import {BeaconConfig} from "@lodestar/config"; import {sleep, toHex} from "@lodestar/utils"; import {ForkName} from "@lodestar/params"; -import {LoggerNode} from "@lodestar/logger"; +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"; diff --git a/packages/beacon-node/src/network/peers/discover.ts b/packages/beacon-node/src/network/peers/discover.ts index a96c7b79d31e..93a633606bc4 100644 --- a/packages/beacon-node/src/network/peers/discover.ts +++ b/packages/beacon-node/src/network/peers/discover.ts @@ -5,7 +5,7 @@ import {BeaconConfig} from "@lodestar/config"; 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"; +import {LoggerNode} from "@lodestar/logger/node"; import {NetworkCoreMetrics} from "../core/metrics.js"; import {Libp2p} from "../interface.js"; import {ENRKey, SubnetType} from "../metadata.js"; diff --git a/packages/beacon-node/src/network/peers/peerManager.ts b/packages/beacon-node/src/network/peers/peerManager.ts index d4212050bb41..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 {LoggerNode} from "@lodestar/logger"; +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"; diff --git a/packages/beacon-node/src/node/nodejs.ts b/packages/beacon-node/src/node/nodejs.ts index 8675e5b61f03..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 {LoggerNode} from "@lodestar/logger"; +import {LoggerNode} from "@lodestar/logger/node"; import {Api, ServerApi} from "@lodestar/api"; import {BeaconStateAllForks} from "@lodestar/state-transition"; import {ProcessShutdownCallback} from "@lodestar/validator"; diff --git a/packages/logger/package.json b/packages/logger/package.json index 1f862dfa3902..93f41f5a7c88 100644 --- a/packages/logger/package.json +++ b/packages/logger/package.json @@ -17,11 +17,14 @@ ".": { "import": "./lib/index.js" }, - "./logger": { - "import": "./lib/logger/index.js" + "./browser": { + "import": "./lib/loggers/browser.js" }, "./node": { - "import": "./lib/node/index.js" + "import": "./lib/loggers/node.js" + }, + "./empty": { + "import": "./lib/loggers/empty.js" } }, "files": [ diff --git a/packages/logger/src/env.ts b/packages/logger/src/env.ts deleted file mode 100644 index cf271aaeaeb8..000000000000 --- a/packages/logger/src/env.ts +++ /dev/null @@ -1,42 +0,0 @@ -import winston from "winston"; -import {Logger, LogLevel} from "@lodestar/utils"; -import {TimestampFormat} from "./interface.js"; -import {createWinstonLogger} from "./logger/winston.js"; -export {LogLevel}; - -export type LoggerEnvOpts = { - logLevel?: LogLevel; - logFile?: string; - timestampFormat?: TimestampFormat; -}; - -/** - * Run the test with ENVs to control log level: - * ``` - * LOG_LEVEL=debug mocha .ts - * DEBUG=1 mocha .ts - * VERBOSE=1 mocha .ts - * ``` - */ -export function getEnvLogger(module?: string, opts?: LoggerEnvOpts): 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, - }) - ); - } - - 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; -} diff --git a/packages/logger/src/index.ts b/packages/logger/src/index.ts index 557fc74397ac..6c9d549dced8 100644 --- a/packages/logger/src/index.ts +++ b/packages/logger/src/index.ts @@ -1,6 +1,11 @@ -export * from "./logger/index.js"; -export * from "./node/index.js"; +import {LogLevel} from "@lodestar/utils"; + export * from "./interface.js"; -export * from "./browser.js"; -export * from "./empty.js"; -export * from "./env.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; +} diff --git a/packages/logger/src/logger/index.ts b/packages/logger/src/logger/index.ts deleted file mode 100644 index 7faea8da71cb..000000000000 --- a/packages/logger/src/logger/index.ts +++ /dev/null @@ -1,2 +0,0 @@ -export * from "./format.js"; -export * from "./winston.js"; diff --git a/packages/logger/src/browser.ts b/packages/logger/src/loggers/browser.ts similarity index 96% rename from packages/logger/src/browser.ts rename to packages/logger/src/loggers/browser.ts index 6727f315780a..72e963c86a61 100644 --- a/packages/logger/src/browser.ts +++ b/packages/logger/src/loggers/browser.ts @@ -1,7 +1,7 @@ import winston from "winston"; import Transport from "winston-transport"; import {LogLevel, Logger} from "@lodestar/utils"; -import {createWinstonLogger} from "./logger/index.js"; +import {createWinstonLogger} from "./winston.js"; export type BrowserLoggerOpts = { level: LogLevel; diff --git a/packages/logger/src/empty.ts b/packages/logger/src/loggers/empty.ts similarity index 100% rename from packages/logger/src/empty.ts rename to packages/logger/src/loggers/empty.ts diff --git a/packages/logger/src/node/index.ts b/packages/logger/src/loggers/node.ts similarity index 96% rename from packages/logger/src/node/index.ts rename to packages/logger/src/loggers/node.ts index e786f3e3fec9..51da39d8dd2a 100644 --- a/packages/logger/src/node/index.ts +++ b/packages/logger/src/loggers/node.ts @@ -3,8 +3,9 @@ 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 {getFormat, WinstonLogger} from "../logger/index.js"; -import {ConsoleDynamicLevel} from "./consoleTransport.js"; +import {ConsoleDynamicLevel} from "../utils/consoleTransport.js"; +import {getFormat} from "../utils/format.js"; +import {WinstonLogger} from "./winston.js"; const DATE_PATTERN = "YYYY-MM-DD"; diff --git a/packages/logger/src/logger/winston.ts b/packages/logger/src/loggers/winston.ts similarity index 97% rename from packages/logger/src/logger/winston.ts rename to packages/logger/src/loggers/winston.ts index 75def6fa1051..d650a5430cd4 100644 --- a/packages/logger/src/logger/winston.ts +++ b/packages/logger/src/loggers/winston.ts @@ -1,8 +1,8 @@ import winston from "winston"; import type {Logger as Winston} from "winston"; import {Logger, LoggerOptions, LogLevel, logLevelNum} from "../interface.js"; -import {getFormat} from "./format.js"; -import {LogData} from "./json.js"; +import {getFormat} from "../utils/format.js"; +import {LogData} from "../utils/json.js"; // # How to configure Winston log level? // diff --git a/packages/logger/src/node/consoleTransport.ts b/packages/logger/src/utils/consoleTransport.ts similarity index 100% rename from packages/logger/src/node/consoleTransport.ts rename to packages/logger/src/utils/consoleTransport.ts diff --git a/packages/logger/src/logger/format.ts b/packages/logger/src/utils/format.ts similarity index 100% rename from packages/logger/src/logger/format.ts rename to packages/logger/src/utils/format.ts diff --git a/packages/logger/src/logger/json.ts b/packages/logger/src/utils/json.ts similarity index 100% rename from packages/logger/src/logger/json.ts rename to packages/logger/src/utils/json.ts diff --git a/packages/logger/src/logger/timeFormat.ts b/packages/logger/src/utils/timeFormat.ts similarity index 100% rename from packages/logger/src/logger/timeFormat.ts rename to packages/logger/src/utils/timeFormat.ts diff --git a/packages/logger/test/unit/logger/json.test.ts b/packages/logger/test/unit/logger/json.test.ts index 42571fc34ffe..06352fc5f171 100644 --- a/packages/logger/test/unit/logger/json.test.ts +++ b/packages/logger/test/unit/logger/json.test.ts @@ -3,7 +3,7 @@ import "../../setup.js"; import {expect} from "chai"; import {fromHexString, toHexString} from "@chainsafe/ssz"; import {LodestarError} from "@lodestar/utils"; -import {logCtxToJson, logCtxToString} from "../../../src/logger/json.js"; +import {logCtxToJson, logCtxToString} from "../../../src/utils/json.js"; describe("Json helper", () => { const circularReference = {}; diff --git a/packages/logger/test/unit/logger/timeFormat.test.ts b/packages/logger/test/unit/logger/timeFormat.test.ts index 5537e3d7a68f..62640ff48c2c 100644 --- a/packages/logger/test/unit/logger/timeFormat.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/timeFormat.js"; +import {formatEpochSlotTime} from "../../../src/utils/timeFormat.js"; describe("logger / util / formatEpochSlotTime", () => { const nowSec = 1619171569; diff --git a/packages/logger/test/unit/logger/winston.test.ts b/packages/logger/test/unit/logger/winston.test.ts index 4726e3daed7a..8ca569b7e040 100644 --- a/packages/logger/test/unit/logger/winston.test.ts +++ b/packages/logger/test/unit/logger/winston.test.ts @@ -3,7 +3,8 @@ import {expect} from "chai"; import {MESSAGE} from "triple-beam"; import Transport from "winston-transport"; import {LodestarError, LogLevel} from "@lodestar/utils"; -import {LogData, LogFormat, logFormats, TimestampFormatCode, WinstonLoggerNode} from "../../../src/index.js"; +import {LogData, LogFormat, logFormats, TimestampFormatCode} from "../../../src/index.js"; +import {WinstonLoggerNode} from "../../../src/loggers/node.js"; type WinstonLog = {[MESSAGE]: string}; diff --git a/packages/logger/test/unit/loggerTransport.test.ts b/packages/logger/test/unit/loggerTransport.test.ts index 163aea7d8120..a24a26cbf19f 100644 --- a/packages/logger/test/unit/loggerTransport.test.ts +++ b/packages/logger/test/unit/loggerTransport.test.ts @@ -2,14 +2,8 @@ import fs from "node:fs"; import path from "node:path"; import {expect} from "chai"; import {LodestarError, LogData, LogLevel} from "@lodestar/utils"; -import { - LogFormat, - LoggerNodeOpts, - LoggerNode, - TimestampFormatCode, - getNodeLogger, - logFormats, -} from "../../src/index.js"; +import {LogFormat, TimestampFormatCode, logFormats} from "../../src/index.js"; +import {LoggerNode, LoggerNodeOpts, getNodeLogger} from "../../src/loggers/node.js"; describe("winston logger format and options", () => { type TestCase = { diff --git a/packages/prover/src/utils/logger.ts b/packages/prover/src/utils/logger.ts index 80702d9bdf60..c9e7f00d1ca2 100644 --- a/packages/prover/src/utils/logger.ts +++ b/packages/prover/src/utils/logger.ts @@ -1,5 +1,7 @@ import {Logger} from "@lodestar/utils"; -import {getNodeLogger, getBrowserLogger, getEmptyLogger} from "@lodestar/logger"; +import {getNodeLogger} from "@lodestar/logger/node"; +import {getBrowserLogger} from "@lodestar/logger/browser"; +import {getEmptyLogger} from "@lodestar/logger/empty"; import {LogOptions} from "../interfaces.js"; export function getLogger(opts: LogOptions): Logger { From 1efaf163c13d0795cc0287f5a16ef6b07e9269d3 Mon Sep 17 00:00:00 2001 From: Nazar Hussain Date: Mon, 15 May 2023 16:02:45 +0200 Subject: [PATCH 07/18] Add typesVersion support for exports --- packages/beacon-node/src/network/discv5/index.ts | 1 - packages/logger/package.json | 9 +++++++++ 2 files changed, 9 insertions(+), 1 deletion(-) diff --git a/packages/beacon-node/src/network/discv5/index.ts b/packages/beacon-node/src/network/discv5/index.ts index 3dc1ede715ee..b4f41ce7a8e9 100644 --- a/packages/beacon-node/src/network/discv5/index.ts +++ b/packages/beacon-node/src/network/discv5/index.ts @@ -20,7 +20,6 @@ export type Discv5Opts = { export type Discv5Events = { discovered: (enr: ENR) => void; }; -src / utils / logger.ts; type Discv5WorkerStatus = | {status: "stopped"} diff --git a/packages/logger/package.json b/packages/logger/package.json index 93f41f5a7c88..a25a25425595 100644 --- a/packages/logger/package.json +++ b/packages/logger/package.json @@ -27,6 +27,15 @@ "import": "./lib/loggers/empty.js" } }, + "typesVersions": { + "*": { + "*": [ + "*", + "lib/*", + "lib/*/index" + ] + } + }, "files": [ "lib/**/*.d.ts", "lib/**/*.js", From 2be1d08de21fb8171c4b9867bf578c2938319a4d Mon Sep 17 00:00:00 2001 From: Cayman Date: Mon, 15 May 2023 13:21:36 -0400 Subject: [PATCH 08/18] Fix exports, add getEnvLogger --- packages/logger/src/{loggers => }/browser.ts | 3 ++- packages/logger/src/{loggers => }/empty.ts | 0 packages/logger/src/index.ts | 13 +++++++++++++ packages/logger/src/{loggers => }/node.ts | 6 +++--- packages/logger/src/{loggers => }/winston.ts | 6 +++--- packages/logger/test/unit/logger/winston.test.ts | 2 +- packages/logger/test/unit/loggerTransport.test.ts | 2 +- 7 files changed, 23 insertions(+), 9 deletions(-) rename packages/logger/src/{loggers => }/browser.ts (90%) rename packages/logger/src/{loggers => }/empty.ts (100%) rename packages/logger/src/{loggers => }/node.ts (95%) rename packages/logger/src/{loggers => }/winston.ts (95%) diff --git a/packages/logger/src/loggers/browser.ts b/packages/logger/src/browser.ts similarity index 90% rename from packages/logger/src/loggers/browser.ts rename to packages/logger/src/browser.ts index 72e963c86a61..db65785a83f3 100644 --- a/packages/logger/src/loggers/browser.ts +++ b/packages/logger/src/browser.ts @@ -4,11 +4,12 @@ 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: "prover"}, [new BrowserConsole({level: opts.level})]); + return createWinstonLogger({level: opts.level, module: opts.module ?? ""}, [new BrowserConsole({level: opts.level})]); } class BrowserConsole extends Transport { diff --git a/packages/logger/src/loggers/empty.ts b/packages/logger/src/empty.ts similarity index 100% rename from packages/logger/src/loggers/empty.ts rename to packages/logger/src/empty.ts diff --git a/packages/logger/src/index.ts b/packages/logger/src/index.ts index 6c9d549dced8..6075656fb57d 100644 --- a/packages/logger/src/index.ts +++ b/packages/logger/src/index.ts @@ -1,4 +1,7 @@ +import {Logger} from "@lodestar/utils"; import {LogLevel} from "@lodestar/utils"; +import {BrowserLoggerOpts, getBrowserLogger} from "./browser.js"; +import {getEmptyLogger} from "./empty.js"; export * from "./interface.js"; @@ -9,3 +12,13 @@ export function getEnvLogLevel(): LogLevel | null { if (process.env["VERBOSE"]) return LogLevel.verbose; return null; } + +export type LoggerEnvOpts = BrowserLoggerOpts; + +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/loggers/node.ts b/packages/logger/src/node.ts similarity index 95% rename from packages/logger/src/loggers/node.ts rename to packages/logger/src/node.ts index 51da39d8dd2a..c7e231034512 100644 --- a/packages/logger/src/loggers/node.ts +++ b/packages/logger/src/node.ts @@ -2,9 +2,9 @@ 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 {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"; diff --git a/packages/logger/src/loggers/winston.ts b/packages/logger/src/winston.ts similarity index 95% rename from packages/logger/src/loggers/winston.ts rename to packages/logger/src/winston.ts index d650a5430cd4..a169b168833a 100644 --- a/packages/logger/src/loggers/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, LogLevel, logLevelNum} from "../interface.js"; -import {getFormat} from "../utils/format.js"; -import {LogData} from "../utils/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? // diff --git a/packages/logger/test/unit/logger/winston.test.ts b/packages/logger/test/unit/logger/winston.test.ts index 8ca569b7e040..5ad5bda9b8b9 100644 --- a/packages/logger/test/unit/logger/winston.test.ts +++ b/packages/logger/test/unit/logger/winston.test.ts @@ -4,7 +4,7 @@ import {MESSAGE} from "triple-beam"; import Transport from "winston-transport"; import {LodestarError, LogLevel} from "@lodestar/utils"; import {LogData, LogFormat, logFormats, TimestampFormatCode} from "../../../src/index.js"; -import {WinstonLoggerNode} from "../../../src/loggers/node.js"; +import {WinstonLoggerNode} from "../../../src/node.js"; type WinstonLog = {[MESSAGE]: string}; diff --git a/packages/logger/test/unit/loggerTransport.test.ts b/packages/logger/test/unit/loggerTransport.test.ts index a24a26cbf19f..997261ee60fb 100644 --- a/packages/logger/test/unit/loggerTransport.test.ts +++ b/packages/logger/test/unit/loggerTransport.test.ts @@ -3,7 +3,7 @@ import path from "node:path"; import {expect} from "chai"; import {LodestarError, LogData, LogLevel} from "@lodestar/utils"; import {LogFormat, TimestampFormatCode, logFormats} from "../../src/index.js"; -import {LoggerNode, LoggerNodeOpts, getNodeLogger} from "../../src/loggers/node.js"; +import {LoggerNode, LoggerNodeOpts, getNodeLogger} from "../../src/node.js"; describe("winston logger format and options", () => { type TestCase = { From eefaa2f24ff7342d188797f9697830d6213454bb Mon Sep 17 00:00:00 2001 From: Cayman Date: Mon, 15 May 2023 13:21:58 -0400 Subject: [PATCH 09/18] Fix logger usage and tests --- .../e2e/api/impl/lightclient/endpoint.test.ts | 2 +- .../test/e2e/api/lodestar/lodestar.test.ts | 4 ++-- .../test/e2e/chain/lightclient.test.ts | 8 +++---- .../e2e/doppelganger/doppelganger.test.ts | 4 ++-- .../test/sim/merge-interop.test.ts | 7 ++++-- .../beacon-node/test/sim/mergemock.test.ts | 10 +++++--- .../test/sim/withdrawal-interop.test.ts | 10 +++++--- .../test/unit/chain/prepareNextSlot.test.ts | 7 +++--- packages/beacon-node/test/utils/logger.ts | 19 ++++++++++++--- .../beacon-node/test/utils/mocks/logger.ts | 24 +++++++++++-------- .../beacon-node/test/utils/node/beacon.ts | 5 ++-- packages/cli/src/cmds/beacon/handler.ts | 2 +- packages/cli/src/cmds/lightclient/handler.ts | 2 +- packages/cli/src/cmds/validator/handler.ts | 2 +- .../validator/slashingProtection/export.ts | 2 +- .../validator/slashingProtection/import.ts | 2 +- packages/cli/src/util/logger.ts | 3 ++- packages/prover/test/mocks/request_handler.ts | 4 ++-- .../prover/test/unit/utils/execution.test.ts | 4 ++-- packages/reqresp/test/unit/ReqResp.test.ts | 2 +- .../reqresp/test/unit/request/index.test.ts | 2 +- .../reqresp/test/unit/response/index.test.ts | 2 +- 22 files changed, 79 insertions(+), 48 deletions(-) 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 adb368257395..5e079e204a9f 100644 --- a/packages/beacon-node/test/sim/merge-interop.test.ts +++ b/packages/beacon-node/test/sim/merge-interop.test.ts @@ -266,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 702d5acc0eb2..8c18232a7b19 100644 --- a/packages/beacon-node/test/utils/logger.ts +++ b/packages/beacon-node/test/utils/logger.ts @@ -1,8 +1,9 @@ import {LogLevel} from "@lodestar/utils"; -import {getEnvLogger, LoggerEnvOpts} from "@lodestar/logger"; +import {getNodeLogger, LoggerNode, LoggerNodeOpts} from "@lodestar/logger/node"; +import {getEnvLogLevel} from "@lodestar/logger"; export {LogLevel}; -export type TestLoggerOpts = LoggerEnvOpts; +export type TestLoggerOpts = LoggerNodeOpts; /** * Run the test with ENVs to control log level: @@ -12,4 +13,16 @@ export type TestLoggerOpts = LoggerEnvOpts; * VERBOSE=1 mocha .ts * ``` */ -export const testLogger = getEnvLogger; +export const testLogger = (module?: string, opts?: TestLoggerOpts): LoggerNode => { + if (opts == null) { + opts = {} as LoggerNodeOpts; + } + if (module) { + opts.module = module; + } + const level = getEnvLogLevel(); + if (level != null) { + opts.level = level; + } + 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/src/cmds/beacon/handler.ts b/packages/cli/src/cmds/beacon/handler.ts index 27f8b9627af9..eedc5d3a334d 100644 --- a/packages/cli/src/cmds/beacon/handler.ts +++ b/packages/cli/src/cmds/beacon/handler.ts @@ -6,7 +6,7 @@ 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"; +import {LoggerNode, getNodeLogger} from "@lodestar/logger/node"; import {GlobalArgs, parseBeaconNodeArgs} from "../../options/index.js"; import {BeaconNodeOptions, getBeaconConfigFromArgs} from "../../config/index.js"; diff --git a/packages/cli/src/cmds/lightclient/handler.ts b/packages/cli/src/cmds/lightclient/handler.ts index 126e649389ff..11e5ed743d54 100644 --- a/packages/cli/src/cmds/lightclient/handler.ts +++ b/packages/cli/src/cmds/lightclient/handler.ts @@ -3,7 +3,7 @@ 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"; +import {getNodeLogger} from "@lodestar/logger/node"; import {getBeaconConfigFromArgs} from "../../config/beaconParams.js"; import {getGlobalPaths} from "../../paths/global.js"; import {parseLoggerArgs} from "../../util/logger.js"; diff --git a/packages/cli/src/cmds/validator/handler.ts b/packages/cli/src/cmds/validator/handler.ts index 88f4589c4baf..4b09afc687fe 100644 --- a/packages/cli/src/cmds/validator/handler.ts +++ b/packages/cli/src/cmds/validator/handler.ts @@ -10,7 +10,7 @@ import { } from "@lodestar/validator"; import {getMetrics, MetricsRegister} from "@lodestar/validator"; import {RegistryMetricCreator, collectNodeJSMetrics, HttpMetricsServer, MonitoringService} from "@lodestar/beacon-node"; -import {getNodeLogger} from "@lodestar/logger"; +import {getNodeLogger} from "@lodestar/logger/node"; import {getBeaconConfigFromArgs} from "../../config/index.js"; import {GlobalArgs} from "../../options/index.js"; import {YargsError, cleanOldLogFiles, getDefaultGraffiti, mkdir, parseLoggerArgs} from "../../util/index.js"; diff --git a/packages/cli/src/cmds/validator/slashingProtection/export.ts b/packages/cli/src/cmds/validator/slashingProtection/export.ts index e2012d6b78f9..3557aa6ee456 100644 --- a/packages/cli/src/cmds/validator/slashingProtection/export.ts +++ b/packages/cli/src/cmds/validator/slashingProtection/export.ts @@ -1,7 +1,7 @@ import path from "node:path"; import {toHexString} from "@chainsafe/ssz"; import {InterchangeFormatVersion} from "@lodestar/validator"; -import {getNodeLogger} from "@lodestar/logger"; +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"; diff --git a/packages/cli/src/cmds/validator/slashingProtection/import.ts b/packages/cli/src/cmds/validator/slashingProtection/import.ts index 4e2b86bfa6eb..ff9bad77c350 100644 --- a/packages/cli/src/cmds/validator/slashingProtection/import.ts +++ b/packages/cli/src/cmds/validator/slashingProtection/import.ts @@ -1,7 +1,7 @@ import fs from "node:fs"; import path from "node:path"; import {Interchange} from "@lodestar/validator"; -import {getNodeLogger} from "@lodestar/logger"; +import {getNodeLogger} from "@lodestar/logger/node"; import {CliCommand} from "../../../util/index.js"; import {parseLoggerArgs} from "../../../util/logger.js"; import {GlobalArgs} from "../../../options/index.js"; diff --git a/packages/cli/src/util/logger.ts b/packages/cli/src/util/logger.ts index 4d5a8e2bd5bb..ada5e79bb3dd 100644 --- a/packages/cli/src/util/logger.ts +++ b/packages/cli/src/util/logger.ts @@ -2,7 +2,8 @@ import path from "node:path"; import fs from "node:fs"; import {ChainForkConfig} from "@lodestar/config"; import {SLOTS_PER_EPOCH} from "@lodestar/params"; -import {LogFormat, LoggerNodeOpts, TimestampFormatCode, logFormats} from "@lodestar/logger"; +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"; diff --git a/packages/prover/test/mocks/request_handler.ts b/packages/prover/test/mocks/request_handler.ts index d762a1d6b100..37453d8ea559 100644 --- a/packages/prover/test/mocks/request_handler.ts +++ b/packages/prover/test/mocks/request_handler.ts @@ -2,7 +2,7 @@ import sinon from "sinon"; import {NetworkName} from "@lodestar/config/networks"; import {ForkConfig} from "@lodestar/config"; import {ELVerifiedRequestHandlerOpts} from "../../src/interfaces.js"; -import {createMockLogger} from "../mocks/logger_mock.js"; +import {getEnvLogger} from "@lodestar/logger"; 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 61de272b0f1e..e382ef86e6ce 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"; 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,7 +19,7 @@ delete invalidAccountProof.accountProof[0]; chai.use(chaiAsPromised); describe("uitls/execution", () => { - const logger = createMockLogger(); + const logger = getEnvLogger(); describe("isValidAccount", () => { it("should return true if account is valid", async () => { diff --git a/packages/reqresp/test/unit/ReqResp.test.ts b/packages/reqresp/test/unit/ReqResp.test.ts index 4891b3c55c42..26a68ce02d25 100644 --- a/packages/reqresp/test/unit/ReqResp.test.ts +++ b/packages/reqresp/test/unit/ReqResp.test.ts @@ -2,7 +2,7 @@ import {expect} from "chai"; import {Libp2p} from "libp2p"; import sinon from "sinon"; import {Logger} from "@lodestar/utils"; -import {getEmptyLogger} from "@lodestar/logger"; +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"; diff --git a/packages/reqresp/test/unit/request/index.test.ts b/packages/reqresp/test/unit/request/index.test.ts index 602fd5b8174f..af8fc5fff09f 100644 --- a/packages/reqresp/test/unit/request/index.test.ts +++ b/packages/reqresp/test/unit/request/index.test.ts @@ -4,7 +4,7 @@ import {pipe} from "it-pipe"; import {expect} from "chai"; import {Libp2p} from "libp2p"; import sinon from "sinon"; -import {getEmptyLogger} from "@lodestar/logger"; +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"; diff --git a/packages/reqresp/test/unit/response/index.test.ts b/packages/reqresp/test/unit/response/index.test.ts index 08cb912af9cb..d26be58f67d4 100644 --- a/packages/reqresp/test/unit/response/index.test.ts +++ b/packages/reqresp/test/unit/response/index.test.ts @@ -1,7 +1,7 @@ import {PeerId} from "@libp2p/interface-peer-id"; import {expect} from "chai"; import {LodestarError, fromHex} from "@lodestar/utils"; -import {getEmptyLogger} from "@lodestar/logger"; +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"; From 014a28661e6cc8934a370c2e4831bb915e9eb353 Mon Sep 17 00:00:00 2001 From: Cayman Date: Mon, 15 May 2023 13:31:10 -0400 Subject: [PATCH 10/18] Fix logger exports --- packages/logger/package.json | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/packages/logger/package.json b/packages/logger/package.json index a25a25425595..333d40138cb8 100644 --- a/packages/logger/package.json +++ b/packages/logger/package.json @@ -18,13 +18,13 @@ "import": "./lib/index.js" }, "./browser": { - "import": "./lib/loggers/browser.js" + "import": "./lib/browser.js" }, "./node": { - "import": "./lib/loggers/node.js" + "import": "./lib/node.js" }, "./empty": { - "import": "./lib/loggers/empty.js" + "import": "./lib/empty.js" } }, "typesVersions": { From 373ba77f853c7bfa4fb426febf189d23fc1a14ff Mon Sep 17 00:00:00 2001 From: Cayman Date: Mon, 15 May 2023 13:36:53 -0400 Subject: [PATCH 11/18] Fix linter error --- packages/prover/test/mocks/request_handler.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/prover/test/mocks/request_handler.ts b/packages/prover/test/mocks/request_handler.ts index 37453d8ea559..eaf9749de8fb 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 {ELVerifiedRequestHandlerOpts} from "../../src/interfaces.js"; import {getEnvLogger} from "@lodestar/logger"; +import {ELVerifiedRequestHandlerOpts} from "../../src/interfaces.js"; import {ProofProvider} from "../../src/proof_provider/proof_provider.js"; import {ELRequestPayload, ELResponse} from "../../src/types.js"; import {ELBlock} from "../../src/types.js"; From d4df980865dd420d88455eca5f4284ae8e7f0c0c Mon Sep 17 00:00:00 2001 From: Cayman Date: Mon, 15 May 2023 13:54:26 -0400 Subject: [PATCH 12/18] Fix logger unit test --- packages/logger/test/unit/loggerTransport.test.ts | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) diff --git a/packages/logger/test/unit/loggerTransport.test.ts b/packages/logger/test/unit/loggerTransport.test.ts index 997261ee60fb..255e804dd2b0 100644 --- a/packages/logger/test/unit/loggerTransport.test.ts +++ b/packages/logger/test/unit/loggerTransport.test.ts @@ -60,7 +60,11 @@ describe("winston logger format and options", () => { it(`${id} ${format} output`, async () => { stdoutHook = hookProcessStdout(); - const logger = getNodeLogger({level: LogLevel.info, format}); + const logger = getNodeLogger({ + level: LogLevel.info, + format, + timestampFormat: {format: TimestampFormatCode.Hidden}, + }); logger.warn(message, context, error); From 142ace689ec58dc35a696b4ef7db6d91fced282c Mon Sep 17 00:00:00 2001 From: Cayman Date: Mon, 15 May 2023 14:11:17 -0400 Subject: [PATCH 13/18] Fix beacon node test logger --- packages/beacon-node/test/utils/logger.ts | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/packages/beacon-node/test/utils/logger.ts b/packages/beacon-node/test/utils/logger.ts index 8c18232a7b19..ea2e4247e87a 100644 --- a/packages/beacon-node/test/utils/logger.ts +++ b/packages/beacon-node/test/utils/logger.ts @@ -21,8 +21,6 @@ export const testLogger = (module?: string, opts?: TestLoggerOpts): LoggerNode = opts.module = module; } const level = getEnvLogLevel(); - if (level != null) { - opts.level = level; - } + opts.level = level ?? LogLevel.info; return getNodeLogger(opts); }; From 4f375c50349fd748504b34db3f24fe53fc1d78e8 Mon Sep 17 00:00:00 2001 From: Cayman Date: Mon, 15 May 2023 15:56:23 -0400 Subject: [PATCH 14/18] Fix more tests --- packages/cli/test/utils.ts | 25 +++++++++++++++++++++++-- packages/logger/src/index.ts | 2 +- 2 files changed, 24 insertions(+), 3 deletions(-) diff --git a/packages/cli/test/utils.ts b/packages/cli/test/utils.ts index 62805bd47290..15e82f781d96 100644 --- a/packages/cli/test/utils.ts +++ b/packages/cli/test/utils.ts @@ -1,14 +1,35 @@ import fs from "node:fs"; import path from "node:path"; import tmp from "tmp"; -import {getEnvLogger} from "@lodestar/logger"; +import {LogLevel, getEnvLogLevel} from "@lodestar/logger"; +import {LoggerNode, LoggerNodeOpts, getNodeLogger} from "@lodestar/logger/node"; export const networkDev = "dev"; const tmpDir = tmp.dirSync({unsafeCleanup: true}); export const testFilesDir = tmpDir.name; -export const testLogger = getEnvLogger; +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/logger/src/index.ts b/packages/logger/src/index.ts index 6075656fb57d..450fba85304b 100644 --- a/packages/logger/src/index.ts +++ b/packages/logger/src/index.ts @@ -17,7 +17,7 @@ export type LoggerEnvOpts = BrowserLoggerOpts; export function getEnvLogger(opts?: Partial): Logger { const level = opts?.level ?? getEnvLogLevel(); - if (level !== null) { + if (level != null) { return getBrowserLogger({...opts, level}); } return getEmptyLogger(); From 77a3d00d43a16dac9619979b160798c21e1b3b79 Mon Sep 17 00:00:00 2001 From: Cayman Date: Mon, 15 May 2023 16:12:54 -0400 Subject: [PATCH 15/18] Fix more tests --- packages/cli/test/unit/cmds/beacon.test.ts | 2 ++ 1 file changed, 2 insertions(+) diff --git a/packages/cli/test/unit/cmds/beacon.test.ts b/packages/cli/test/unit/cmds/beacon.test.ts index a7d8d67b2a02..8b8d4e3d8ee2 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,7 @@ describe("initPeerIdAndEnr", () => { // eslint-disable-next-line @typescript-eslint/explicit-function-return-type async function runBeaconHandlerInit(args: Partial) { return beaconHandlerInit({ + logLevel: LogLevel.info, dataDir: testFilesDir, ...args, } as BeaconArgs & GlobalArgs); From 97b1dd041e89ec513b6aa5876971679c93a97d52 Mon Sep 17 00:00:00 2001 From: Cayman Date: Mon, 15 May 2023 16:32:13 -0400 Subject: [PATCH 16/18] Fix more tests --- packages/cli/test/unit/cmds/beacon.test.ts | 1 + 1 file changed, 1 insertion(+) diff --git a/packages/cli/test/unit/cmds/beacon.test.ts b/packages/cli/test/unit/cmds/beacon.test.ts index 8b8d4e3d8ee2..8891e3f8d3a8 100644 --- a/packages/cli/test/unit/cmds/beacon.test.ts +++ b/packages/cli/test/unit/cmds/beacon.test.ts @@ -186,6 +186,7 @@ describe("initPeerIdAndEnr", () => { async function runBeaconHandlerInit(args: Partial) { return beaconHandlerInit({ logLevel: LogLevel.info, + logFileLevel: LogLevel.debug, dataDir: testFilesDir, ...args, } as BeaconArgs & GlobalArgs); From f5be1ddc2ddc506a30471391daea3e52bb43edc1 Mon Sep 17 00:00:00 2001 From: Cayman Date: Mon, 15 May 2023 16:43:00 -0400 Subject: [PATCH 17/18] Fix browser tests --- packages/prover/src/utils/logger.ts | 10 +--------- 1 file changed, 1 insertion(+), 9 deletions(-) diff --git a/packages/prover/src/utils/logger.ts b/packages/prover/src/utils/logger.ts index c9e7f00d1ca2..8046d7eaba77 100644 --- a/packages/prover/src/utils/logger.ts +++ b/packages/prover/src/utils/logger.ts @@ -1,5 +1,4 @@ import {Logger} from "@lodestar/utils"; -import {getNodeLogger} from "@lodestar/logger/node"; import {getBrowserLogger} from "@lodestar/logger/browser"; import {getEmptyLogger} from "@lodestar/logger/empty"; import {LogOptions} from "../interfaces.js"; @@ -7,14 +6,7 @@ import {LogOptions} from "../interfaces.js"; export function getLogger(opts: LogOptions): Logger { if (opts.logger) return opts.logger; - // Code is running in the node environment - if (opts.logLevel && process !== undefined) { - // TODO for @nazarhussain: Any issue with pulling this code into the Web3Provider path? - // Can we just use the console.log logger for all code paths? - return getNodeLogger({level: opts.logLevel}); - } - - if (opts.logLevel && process === undefined) { + if (opts.logLevel) { return getBrowserLogger({level: opts.logLevel}); } From cd1df8a6e1f1d526e6805c2bfa397f402b206678 Mon Sep 17 00:00:00 2001 From: Cayman Date: Mon, 15 May 2023 17:57:33 -0400 Subject: [PATCH 18/18] Move env logger to separate subpath export --- packages/beacon-node/test/utils/logger.ts | 2 +- packages/cli/test/utils.ts | 3 ++- .../db/test/unit/controller/level.test.ts | 2 +- packages/logger/package.json | 3 +++ packages/logger/src/env.ts | 20 ++++++++++++++++ packages/logger/src/index.ts | 23 ------------------- packages/prover/test/mocks/request_handler.ts | 2 +- .../prover/test/unit/utils/execution.test.ts | 2 +- packages/validator/test/utils/logger.ts | 2 +- 9 files changed, 30 insertions(+), 29 deletions(-) create mode 100644 packages/logger/src/env.ts diff --git a/packages/beacon-node/test/utils/logger.ts b/packages/beacon-node/test/utils/logger.ts index ea2e4247e87a..b3382cc221e2 100644 --- a/packages/beacon-node/test/utils/logger.ts +++ b/packages/beacon-node/test/utils/logger.ts @@ -1,6 +1,6 @@ import {LogLevel} from "@lodestar/utils"; import {getNodeLogger, LoggerNode, LoggerNodeOpts} from "@lodestar/logger/node"; -import {getEnvLogLevel} from "@lodestar/logger"; +import {getEnvLogLevel} from "@lodestar/logger/env"; export {LogLevel}; export type TestLoggerOpts = LoggerNodeOpts; diff --git a/packages/cli/test/utils.ts b/packages/cli/test/utils.ts index 15e82f781d96..51fd5f3742b2 100644 --- a/packages/cli/test/utils.ts +++ b/packages/cli/test/utils.ts @@ -1,8 +1,9 @@ import fs from "node:fs"; import path from "node:path"; import tmp from "tmp"; -import {LogLevel, getEnvLogLevel} from "@lodestar/logger"; +import {getEnvLogLevel} from "@lodestar/logger/env"; import {LoggerNode, LoggerNodeOpts, getNodeLogger} from "@lodestar/logger/node"; +import {LogLevel} from "@lodestar/utils"; export const networkDev = "dev"; diff --git a/packages/db/test/unit/controller/level.test.ts b/packages/db/test/unit/controller/level.test.ts index 2a3c9c25f1b0..d0a23919d8cf 100644 --- a/packages/db/test/unit/controller/level.test.ts +++ b/packages/db/test/unit/controller/level.test.ts @@ -2,7 +2,7 @@ import {execSync} from "node:child_process"; import {expect} from "chai"; import leveldown from "leveldown"; import all from "it-all"; -import {getEnvLogger} from "@lodestar/logger"; +import {getEnvLogger} from "@lodestar/logger/env"; import {LevelDbController} from "../../../src/controller/index.js"; describe("LevelDB controller", () => { diff --git a/packages/logger/package.json b/packages/logger/package.json index 333d40138cb8..f89e09cd72c7 100644 --- a/packages/logger/package.json +++ b/packages/logger/package.json @@ -20,6 +20,9 @@ "./browser": { "import": "./lib/browser.js" }, + "./env": { + "import": "./lib/env.js" + }, "./node": { "import": "./lib/node.js" }, 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 index 450fba85304b..96d65789f80b 100644 --- a/packages/logger/src/index.ts +++ b/packages/logger/src/index.ts @@ -1,24 +1 @@ -import {Logger} from "@lodestar/utils"; -import {LogLevel} from "@lodestar/utils"; -import {BrowserLoggerOpts, getBrowserLogger} from "./browser.js"; -import {getEmptyLogger} from "./empty.js"; - export * from "./interface.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 type LoggerEnvOpts = BrowserLoggerOpts; - -export function getEnvLogger(opts?: Partial): Logger { - const level = opts?.level ?? getEnvLogLevel(); - if (level != null) { - return getBrowserLogger({...opts, level}); - } - return getEmptyLogger(); -} diff --git a/packages/prover/test/mocks/request_handler.ts b/packages/prover/test/mocks/request_handler.ts index eaf9749de8fb..5f474166a4ae 100644 --- a/packages/prover/test/mocks/request_handler.ts +++ b/packages/prover/test/mocks/request_handler.ts @@ -1,7 +1,7 @@ import sinon from "sinon"; import {NetworkName} from "@lodestar/config/networks"; import {ForkConfig} from "@lodestar/config"; -import {getEnvLogger} from "@lodestar/logger"; +import {getEnvLogger} from "@lodestar/logger/env"; import {ELVerifiedRequestHandlerOpts} from "../../src/interfaces.js"; import {ProofProvider} from "../../src/proof_provider/proof_provider.js"; import {ELRequestPayload, ELResponse} from "../../src/types.js"; diff --git a/packages/prover/test/unit/utils/execution.test.ts b/packages/prover/test/unit/utils/execution.test.ts index e382ef86e6ce..dc2702e5f9d0 100644 --- a/packages/prover/test/unit/utils/execution.test.ts +++ b/packages/prover/test/unit/utils/execution.test.ts @@ -2,7 +2,7 @@ import {expect} from "chai"; import chai from "chai"; import chaiAsPromised from "chai-as-promised"; import deepmerge from "deepmerge"; -import {getEnvLogger} from "@lodestar/logger"; +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"; diff --git a/packages/validator/test/utils/logger.ts b/packages/validator/test/utils/logger.ts index 3f46e6f8dfbf..6077b23a9583 100644 --- a/packages/validator/test/utils/logger.ts +++ b/packages/validator/test/utils/logger.ts @@ -1,4 +1,4 @@ -import {getEnvLogger} from "@lodestar/logger"; +import {getEnvLogger} from "@lodestar/logger/env"; import {getLoggerVc} from "../../src/util/index.js"; import {ClockMock} from "./clock.js";