DefaultLogger writes logs to console always and some improvements (#7971

) Co-authored-by: Arda TANRIKULU <[email protected]>
ardatan · Nov 20, 2024 · 9873b33 · 9873b33
1 parent 2ee38a8
commit 9873b33
Show file tree

Hide file tree

Showing 6 changed files with 73 additions and 90 deletions.
diff --git a/.changeset/soft-icons-sparkle.md 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
@@ -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
@@ -38,9 +38,9 @@ describe('Polling Test', () => {
       },
     });
     await new Promise<void>(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<void>(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
@@ -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
@@ -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<typeof program.opts> {
 }
 
 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
@@ -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) +
-              '...' +
-              '<Message is trimmed. Enable DEBUG=1 to see the full message.>'
-            );
-          }
-          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 {