Improve Logging Experience (#3860)

* Improve Logging Experience

* Remove resolutions

.changeset/many-cows-hammer.md

@@ -0,0 +1,9 @@
+---
+'@graphql-mesh/cli': minor
+'@graphql-mesh/config': minor
+'@graphql-mesh/runtime': minor
+'@graphql-mesh/types': minor
+'@graphql-mesh/utils': minor
+---
+
+Improve Logging Experience

packages/cli/src/commands/serve/graphql-handler.ts

@@ -1,6 +1,6 @@
 import { MeshInstance } from '@graphql-mesh/runtime';
 import { RequestHandler } from 'express';
-import { createServer, useExtendContext } from '@graphql-yoga/node';
+import { createServer, useExtendContext, useLogger } from '@graphql-yoga/node';
 
 export const graphqlHandler = (
   mesh$: Promise<MeshInstance>,
@@ -19,6 +19,14 @@ export const graphqlHandler = (
           cookies: req.cookies,
           res,
         })),
+        useLogger({
+          skipIntrospection: true,
+          logFn: (eventName, { args }) => {
+            if (eventName.endsWith('-start')) {
+              mesh.logger.debug(() => [`\t headers: `, args.contextValue.headers]);
+            }
+          },
+        }),
       ],
       logging: mesh.logger,
       maskedErrors: false,

packages/cli/src/commands/serve/serve.ts

@@ -89,7 +89,7 @@ export async function serveMesh(
         });
         logger.info(`${cliParams.serveMessage}: ${serverUrl}`);
         registerTerminateHandler(eventName => {
-          const eventLogger = logger.child(`${eventName}💀`);
+          const eventLogger = logger.child(`${eventName}  💀`);
           eventLogger.info(`Destroying the server`);
           mesh.destroy();
         });
@@ -275,7 +275,7 @@ export async function serveMesh(
       httpServer,
       app,
       readyFlag,
-      logger: logger,
+      logger,
     }));
   }
   return null;

packages/cli/src/config.ts

@@ -1,18 +1,23 @@
 import { ConfigProcessOptions, processConfig } from '@graphql-mesh/config';
 import { jsonSchema, YamlConfig } from '@graphql-mesh/types';
-import { defaultImportFn, loadYaml } from '@graphql-mesh/utils';
+import { defaultImportFn, loadYaml, DefaultLogger } from '@graphql-mesh/utils';
 import Ajv from 'ajv';
 import { cosmiconfig, defaultLoaders } from 'cosmiconfig';
 import { path } from '@graphql-mesh/cross-helpers';
 
-export function validateConfig(config: any): asserts config is YamlConfig.Config {
+export function validateConfig(config: any, filepath: string): asserts config is YamlConfig.Config {
   const ajv = new Ajv({
     strict: false,
   } as any);
   jsonSchema.$schema = undefined;
   const isValid = ajv.validate(jsonSchema, config);
   if (!isValid) {
-    console.warn(`Configuration is not valid:\n${ajv.errorsText()}`);
+    const logger = new DefaultLogger('🕸️  Mesh - Config');
+    logger.warn(
+      `${filepath} configuration file is not valid:\n${ajv.errorsText(ajv.errors, {
+        separator: '\n',
+      })}\nThis is just a warning! It doesn't have any effects on runtime.`
+    );
   }
 }
 
@@ -48,7 +53,7 @@ export async function findAndParseConfig(options?: ConfigProcessOptions) {
   }
 
   const config = results.config;
-  validateConfig(config);
+  validateConfig(config, results.filepath);
   return processConfig(config, { dir, ...restOptions });
 }
 

packages/cli/src/handleFatalError.ts

@@ -1,7 +1,7 @@
 import { Logger } from '@graphql-mesh/types';
 import { DefaultLogger } from '@graphql-mesh/utils';
 
-export function handleFatalError(e: Error, logger: Logger = new DefaultLogger('🕸️')): any {
+export function handleFatalError(e: Error, logger: Logger = new DefaultLogger('🕸️  Mesh')): any {
   logger.error(e.stack || e.message);
   if (process.env.JEST == null) {
     process.exit(1);

packages/cli/src/index.ts

@@ -16,7 +16,7 @@ import { handleFatalError } from './handleFatalError';
 import { cwd, env } from 'process';
 import yargs from 'yargs';
 import { hideBin } from 'yargs/helpers';
-import { YamlConfig } from '@graphql-mesh/types';
+import { Logger, YamlConfig } from '@graphql-mesh/types';
 import { register as tsNodeRegister } from 'ts-node';
 import { register as tsConfigPathsRegister } from 'tsconfig-paths';
 import { config as dotEnvRegister } from 'dotenv';
@@ -45,7 +45,7 @@ export interface GraphQLMeshCLIParams {
 
 export const DEFAULT_CLI_PARAMS: GraphQLMeshCLIParams = {
   commandName: 'mesh',
-  initialLoggerPrefix: '🕸️',
+  initialLoggerPrefix: '🕸️  Mesh',
   configName: 'mesh',
   artifactsDir: '.mesh',
   serveMessage: 'Serving GraphQL Mesh',
@@ -62,7 +62,7 @@ export const DEFAULT_CLI_PARAMS: GraphQLMeshCLIParams = {
 
 export async function graphqlMesh(cliParams = DEFAULT_CLI_PARAMS, args = hideBin(process.argv), cwdPath = cwd()) {
   let baseDir = cwdPath;
-  let logger = new DefaultLogger(cliParams.initialLoggerPrefix);
+  let logger: Logger = new DefaultLogger(cliParams.initialLoggerPrefix);
   return yargs(args)
     .help()
     .option('r', {

packages/config/src/utils.ts

@@ -217,10 +217,10 @@ export async function resolveLogger(
       code: '',
     };
   }
-  const logger = new DefaultLogger('🕸️');
+  const logger = new DefaultLogger('🕸️  Mesh');
   return {
     logger,
     importCode: `import { DefaultLogger } from '@graphql-mesh/utils';`,
-    code: `const logger = new DefaultLogger('🕸️');`,
+    code: `const logger = new DefaultLogger('🕸️  Mesh');`,
   };
 }

packages/runtime/src/get-mesh.ts

@@ -51,7 +51,7 @@ import {
   memoize1,
   parseSelectionSet,
 } from '@graphql-tools/utils';
-import { enableIf, envelop, useErrorHandler, useExtendContext, useLogger, useSchema } from '@envelop/core';
+import { enableIf, envelop, useErrorHandler, useExtendContext, useSchema } from '@envelop/core';
 import { useLiveQuery } from '@envelop/live-query';
 import { CompiledQuery, compileQuery, isCompiledQuery } from 'graphql-jit';
 
@@ -84,7 +84,7 @@ const memoizedGetEnvelopedFactory = memoize1((plugins: EnvelopPlugins) => envelo
 
 export async function getMesh<TMeshContext = any>(options: GetMeshOptions): Promise<MeshInstance<TMeshContext>> {
   const rawSources: RawSourceOutput[] = [];
-  const { pubsub, cache, logger = new DefaultLogger('🕸️'), additionalEnvelopPlugins = [] } = options;
+  const { pubsub, cache, logger = new DefaultLogger('🕸️  Mesh'), additionalEnvelopPlugins = [] } = options;
 
   const getMeshLogger = logger.child('GetMesh');
   getMeshLogger.debug(() => `Getting subschemas from source handlers`);
@@ -366,9 +366,6 @@ See more at https://www.graphql-mesh.com/docs/recipes/live-queries`);
       });
       return useLiveQuery({ liveQueryStore });
     }),
-    useLogger({
-      logFn: (eventName, args) => logger.child(eventName).debug(() => inspect(args)),
-    }),
     useErrorHandler(errors => {
       errors.forEach(error => logger.error(error.stack || error.message));
     }),

packages/types/src/index.ts

@@ -125,15 +125,15 @@ export type GraphQLOperation<TData, TVariables> = TypedDocumentNode<TData, TVari
 
 export type ImportFn = <T = any>(moduleId: string) => Promise<T>;
 
-export type LazyLoggerMessage = (() => string) | string;
+export type LazyLoggerMessage = (() => any | any[]) | any;
 
 export type Logger = {
   name?: string;
-  log: (message: string) => void;
-  warn: (message: string) => void;
-  info: (message: string) => void;
-  error: (message: string) => void;
-  debug: (message: LazyLoggerMessage) => void;
+  log: (...args: any[]) => void;
+  warn: (...args: any[]) => void;
+  info: (...args: any[]) => void;
+  error: (...args: any[]) => void;
+  debug: (...lazyArgs: LazyLoggerMessage[]) => void;
   child: (name: string) => Logger;
 };
 

packages/utils/src/logger.ts

@@ -1,4 +1,5 @@
 import { LazyLoggerMessage, Logger } from '@graphql-mesh/types';
+import { inspect } from '@graphql-tools/utils';
 import chalk from 'chalk';
 
 type MessageTransformer = (msg: string) => string;
@@ -9,36 +10,74 @@ const errorColor: MessageTransformer = chalk.red;
 const debugColor: MessageTransformer = chalk.magenta;
 const titleBold: MessageTransformer = chalk.bold;
 
-function handleLazyMessage(lazyMessage: LazyLoggerMessage) {
-  if (typeof lazyMessage === 'function') {
-    return lazyMessage();
-  }
-  return lazyMessage;
+function handleLazyMessage(...lazyArgs: LazyLoggerMessage[]) {
+  const flattenedArgs = lazyArgs.flat(Infinity).flatMap(arg => {
+    if (typeof arg === 'function') {
+      return arg();
+    }
+    return arg;
+  });
+  return getLoggerMessage(flattenedArgs);
+}
+
+function getLoggerMessage(...args: any[]) {
+  return args
+    .flat(Infinity)
+    .map(arg => (typeof arg === 'string' ? arg : inspect(arg)))
+    .join(` `);
 }
 
 export class DefaultLogger implements Logger {
   constructor(public name?: string) {}
-  log(message: string) {
-    const finalMessage = this.name ? `${titleBold(this.name)}: ${message}` : message;
-    return console.log(finalMessage);
+
+  private getPrefix() {
+    return this.name ? titleBold(this.name) : ``;
   }
 
-  warn(message: string) {
-    return this.log(warnColor(message));
+  log(...args: any[]) {
+    const message = getLoggerMessage(...args);
+    return console.log(`${this.getPrefix()} ${message}`);
   }
 
-  info(message: string) {
-    return this.log(infoColor(message));
+  warn(...args: any[]) {
+    const message = getLoggerMessage(...args);
+    const fullMessage = `⚠️ ${this.getPrefix()} ${warnColor(message)}`;
+    if (console.warn) {
+      console.warn(fullMessage);
+    } else {
+      console.log(fullMessage);
+    }
   }
 
-  error(message: string) {
-    return this.log(errorColor(message));
+  info(...args: any[]) {
+    const message = getLoggerMessage(...args);
+    const fullMessage = `💡 ${this.getPrefix()} ${infoColor(message)}`;
+    if (console.info) {
+      console.info(fullMessage);
+    } else {
+      console.log(fullMessage);
+    }
+  }
+
+  error(...args: any[]) {
+    const message = getLoggerMessage(...args);
+    const fullMessage = `💥 ${this.getPrefix()} ${errorColor(message)}`;
+    if (console.error) {
+      console.error(fullMessage);
+    } else {
+      console.log(fullMessage);
+    }
   }
 
-  debug(lazyMessage: LazyLoggerMessage) {
+  debug(...lazyArgs: LazyLoggerMessage[]) {
     if ((process.env.DEBUG && process.env.DEBUG === '1') || this.name.includes(process.env.DEBUG)) {
-      const message = handleLazyMessage(lazyMessage);
-      return this.log(debugColor(message));
+      const message = handleLazyMessage(lazyArgs);
+      const fullMessage = `🐛 ${this.getPrefix()} ${debugColor(message)}`;
+      if (console.debug) {
+        console.debug(fullMessage);
+      } else {
+        console.log(fullMessage);
+      }
     }
   }