From 9873b33f0cc6c3b3a3c3dc1a0a1cb18c827b8722 Mon Sep 17 00:00:00 2001 From: Denis Badurina Date: Wed, 20 Nov 2024 16:40:34 +0100 Subject: [PATCH] DefaultLogger writes logs to console always and some improvements (#7971) Co-authored-by: Arda TANRIKULU --- .changeset/soft-icons-sparkle.md | 5 + .../logs-to-stderr-results-to-stdout.test.ts | 3 +- .../federation-example/tests/polling.test.ts | 8 +- packages/compose-cli/src/bin.ts | 4 +- packages/compose-cli/src/run.ts | 4 +- packages/legacy/utils/src/logger.ts | 139 +++++++----------- 6 files changed, 73 insertions(+), 90 deletions(-) create mode 100644 .changeset/soft-icons-sparkle.md diff --git a/.changeset/soft-icons-sparkle.md b/.changeset/soft-icons-sparkle.md new file mode 100644 index 0000000000000..a206d60279618 --- /dev/null +++ b/.changeset/soft-icons-sparkle.md @@ -0,0 +1,5 @@ +--- +'@graphql-mesh/utils': minor +--- + +Write logs to console always diff --git a/e2e/logs-to-stderr-results-to-stdout/logs-to-stderr-results-to-stdout.test.ts b/e2e/logs-to-stderr-results-to-stdout/logs-to-stderr-results-to-stdout.test.ts index eb466285c24e0..17fd710cd338b 100644 --- a/e2e/logs-to-stderr-results-to-stdout/logs-to-stderr-results-to-stdout.test.ts +++ b/e2e/logs-to-stderr-results-to-stdout/logs-to-stderr-results-to-stdout.test.ts @@ -6,7 +6,8 @@ it('should write serve logs to stderr', async () => { await using serveInstance = await serve({ supergraph: await fs.tempfile('supergraph.graphql', 'type Query { hello: String }'), }); - expect(serveInstance.getStd('err')).toContain('Serving local supergraph from'); + // stdout from serve because it uses the default logger that uses console.log + expect(serveInstance.getStd('out')).toContain('Serving local supergraph from'); }); it('should write compose output to stdout and logs to stderr', async () => { diff --git a/examples/federation-example/tests/polling.test.ts b/examples/federation-example/tests/polling.test.ts index 5e382f42feaf2..9b85c8b14ac49 100644 --- a/examples/federation-example/tests/polling.test.ts +++ b/examples/federation-example/tests/polling.test.ts @@ -38,9 +38,9 @@ describe('Polling Test', () => { }, }); await new Promise(resolve => { - buildCmd.stderr?.on('data', function stderrListener(data: string) { + buildCmd.stdout?.on('data', function stdoutListener(data: string) { if (data.includes('Done!')) { - buildCmd.stderr?.off('data', stderrListener); + buildCmd.stdout?.off('data', stdoutListener); resolve(); } }); @@ -55,12 +55,12 @@ describe('Polling Test', () => { }, }); await new Promise(resolve => { - serveCmd.stderr?.on('data', function stderrListener(data: string) { + serveCmd.stdout?.on('data', function stdoutListener(data: string) { if (process.env.DEBUG) { console.log(data); } if (data.includes('Serving GraphQL Mesh')) { - serveCmd.stderr?.off('data', stderrListener); + serveCmd.stdout?.off('data', stdoutListener); resolve(); } }); diff --git a/packages/compose-cli/src/bin.ts b/packages/compose-cli/src/bin.ts index c65277bee9d9d..44ef9e1b4a9fc 100644 --- a/packages/compose-cli/src/bin.ts +++ b/packages/compose-cli/src/bin.ts @@ -1,8 +1,10 @@ #!/usr/bin/env node +// eslint-disable-next-line import/no-nodejs-modules +import { Console } from 'console'; import { DefaultLogger } from '@graphql-mesh/utils'; import { run } from './run.js'; -const log = new DefaultLogger(); +const log = new DefaultLogger(undefined, undefined, undefined, new Console(process.stderr)); run({ log }).catch(err => { log.error(err); diff --git a/packages/compose-cli/src/run.ts b/packages/compose-cli/src/run.ts index 70edf74fcd7d3..3aea84aebdbdd 100644 --- a/packages/compose-cli/src/run.ts +++ b/packages/compose-cli/src/run.ts @@ -1,5 +1,7 @@ import 'dotenv/config'; // inject dotenv options to process.env +// eslint-disable-next-line import/no-nodejs-modules +import { Console } from 'node:console'; // eslint-disable-next-line import/no-nodejs-modules import { promises as fsPromises } from 'node:fs'; // eslint-disable-next-line import/no-nodejs-modules @@ -49,7 +51,7 @@ export interface RunOptions extends ReturnType { } export async function run({ - log: rootLog = new DefaultLogger(), + log: rootLog = new DefaultLogger(undefined, undefined, undefined, new Console(process.stderr)), productName = 'Mesh Compose', productDescription = 'compose a GraphQL federated schema from any API service(s)', binName = 'mesh-compose', diff --git a/packages/legacy/utils/src/logger.ts b/packages/legacy/utils/src/logger.ts index 4b9e82c090c37..d65fbc6258974 100644 --- a/packages/legacy/utils/src/logger.ts +++ b/packages/legacy/utils/src/logger.ts @@ -1,5 +1,4 @@ -/* eslint-disable @typescript-eslint/no-unused-expressions -- simply more convenient to do `this.stderr(m) || console.log(m)` */ -import { process, util } from '@graphql-mesh/cross-helpers'; +import { process } from '@graphql-mesh/cross-helpers'; import type { LazyLoggerMessage, Logger } from '@graphql-mesh/types'; type MessageTransformer = (msg: string) => string; @@ -34,134 +33,108 @@ export enum LogLevel { const noop: VoidFunction = () => {}; -function truthy(str: unknown) { - return str === true || str === 1 || ['1', 't', 'true', 'y', 'yes'].includes(String(str)); +function truthy(val: unknown) { + return val === true || val === 1 || ['1', 't', 'true', 'y', 'yes'].includes(String(val)); } function getTimestamp() { return new Date().toISOString(); } +function handleLazyMessage(lazyArgs: LazyLoggerMessage[]) { + return lazyArgs.flat(Infinity).flatMap(arg => { + if (typeof arg === 'function') { + return arg(); + } + return arg; + }); +} + export class DefaultLogger implements Logger { constructor( public name?: string, - public logLevel = truthy(process.env.DEBUG) ? LogLevel.debug : LogLevel.info, - private trim?: number, + public logLevel = truthy(process.env.DEBUG) || + truthy(globalThis.DEBUG) || + (this.name && String(process.env.DEBUG || globalThis.DEBUG || '').includes(this.name)) + ? LogLevel.debug + : LogLevel.info, + /** @deprecated Trimming messages is no longer supported. This argument is unused and will be removed in future versions. */ + _trim?: number | undefined, + private console = globalThis.console, ) {} - private getLoggerMessage({ args = [] }: { args: any[] }) { - return args - .flat(Infinity) - .map(arg => { - if (typeof arg === 'string') { - if (this.trim && arg.length > this.trim) { - return ( - arg.slice(0, this.trim) + - '...' + - '' - ); - } - return arg; - } else if (typeof arg === 'object' && arg?.stack != null) { - return arg.stack; - } - return util.inspect(arg); - }) - .join(' '); - } - - private handleLazyMessage({ lazyArgs }: { lazyArgs: LazyLoggerMessage[] }) { - const flattenedArgs = lazyArgs.flat(Infinity).flatMap(arg => { - if (typeof arg === 'function') { - return arg(); - } - return arg; - }); - return this.getLoggerMessage({ args: flattenedArgs }); - } - - /** - * Tries writing to the process stderr. If unable, will return - * false so that the logger falls back to using the console. - * - * If process stderr is used, a new line is automatically appended - * after the {@link msg}. - */ - private stderr(msg: string) { - if (typeof process?.stderr?.write === 'function') { - process.stderr.write(msg + '\n'); - return true; - } - return false; - } - - private get isDebug() { - return ( - this.logLevel <= LogLevel.debug || - truthy(process.env.DEBUG) || - truthy(globalThis.DEBUG) || - this.name?.includes(process.env.DEBUG || globalThis.DEBUG) - ); - } - private get prefix() { - return this.name ? titleBold(this.name) : ``; + return this.name + ? `${titleBold(this.name.trim())} ` /* trailing space because prefix is directly used in logged message */ + : ``; } + /** Logs a message at {@link LogLevel.info} but without the "INFO" prefix. */ log(...args: any[]) { if (this.logLevel > LogLevel.info) { return noop; } - const message = this.getLoggerMessage({ args }); - const fullMessage = `[${getTimestamp()}] ${this.prefix} ${message}`; - this.stderr(fullMessage) || console.log(fullMessage); + this.console.log( + `[${getTimestamp()}] ${this.prefix}`.trim() /* trim in case prefix is empty */, + ...args, + ); } warn(...args: any[]) { if (this.logLevel > LogLevel.warn) { return noop; } - const message = this.getLoggerMessage({ args }); - const fullMessage = `[${getTimestamp()}] WARN ${this.prefix} ${warnColor(message)}`; - this.stderr(fullMessage) || console.warn(fullMessage); + this.console.warn( + `[${getTimestamp()}] WARN ${this.prefix}${ANSI_CODES.orange}`, + ...args, + ANSI_CODES.reset, + ); } info(...args: any[]) { if (this.logLevel > LogLevel.info) { return noop; } - const message = this.getLoggerMessage({ - args, - }); - const fullMessage = `[${getTimestamp()}] INFO ${this.prefix} ${infoColor(message)}`; - this.stderr(fullMessage) || console.info(fullMessage); + this.console.info( + `[${getTimestamp()}] INFO ${this.prefix}${ANSI_CODES.cyan}`, + ...args, + ANSI_CODES.reset, + ); } error(...args: any[]) { if (this.logLevel > LogLevel.error) { return noop; } - const message = this.getLoggerMessage({ args }); - const fullMessage = `[${getTimestamp()}] ERROR ${this.prefix} ${errorColor(message)}`; - this.stderr(fullMessage) || console.error(fullMessage); + this.console.error( + `[${getTimestamp()}] ERROR ${this.prefix}${ANSI_CODES.red}`, + ...args, + ANSI_CODES.reset, + ); } debug(...lazyArgs: LazyLoggerMessage[]) { - if (!this.isDebug /** also checks whether the loglevel is at least debug */) { + if (this.logLevel > LogLevel.debug) { return noop; } - const message = this.handleLazyMessage({ - lazyArgs, - }); - const fullMessage = `[${getTimestamp()}] DEBUG ${this.prefix} ${debugColor(message)}`; - this.stderr(fullMessage) || console.debug(fullMessage); + const flattenedArgs = handleLazyMessage(lazyArgs); + this.console.debug( + `[${getTimestamp()}] DEBUG ${this.prefix}${ANSI_CODES.magenta}`, + ...flattenedArgs, + ANSI_CODES.reset, + ); } child(name: string): Logger { if (this.name?.includes(name)) { return this; } - return new DefaultLogger(this.name ? `${this.name} - ${name}` : name, this.logLevel); + return new DefaultLogger( + this.name ? `${this.name} - ${name}` : name, + this.logLevel, + undefined, + this.console, + ); } addPrefix(prefix: string): Logger {