From 9eff8a3969ba408996afd9b8e43d020357b0ade6 Mon Sep 17 00:00:00 2001 From: Arda TANRIKULU Date: Wed, 25 Aug 2021 15:12:38 +0300 Subject: [PATCH] enhance(logging): ability to filter debug messages --- .changeset/smooth-scissors-film.md | 11 +++ examples/openapi-subscriptions/.meshrc.yml | 4 +- packages/cli/src/bin.ts | 2 +- packages/cli/src/commands/serve/serve.ts | 78 +++++++++++++++++---- packages/cli/src/handleFatalError.ts | 2 +- packages/cli/src/index.ts | 11 +-- packages/config/src/utils.ts | 4 +- packages/handlers/neo4j/src/index.ts | 12 +++- packages/handlers/postgraphile/src/index.ts | 5 +- packages/runtime/src/get-mesh.ts | 6 +- packages/types/src/index.ts | 2 +- packages/utils/src/logger.ts | 9 +-- 12 files changed, 111 insertions(+), 35 deletions(-) create mode 100644 .changeset/smooth-scissors-film.md diff --git a/.changeset/smooth-scissors-film.md b/.changeset/smooth-scissors-film.md new file mode 100644 index 0000000000000..ccea63bc56f9e --- /dev/null +++ b/.changeset/smooth-scissors-film.md @@ -0,0 +1,11 @@ +--- +'@graphql-mesh/cli': minor +'@graphql-mesh/config': minor +'@graphql-mesh/neo4j': minor +'@graphql-mesh/postgraphile': minor +'@graphql-mesh/runtime': minor +'@graphql-mesh/types': minor +'@graphql-mesh/utils': minor +--- + +enhance(logging): ability to filter debug messages diff --git a/examples/openapi-subscriptions/.meshrc.yml b/examples/openapi-subscriptions/.meshrc.yml index 91d39ae265ad5..5126e3de248ab 100644 --- a/examples/openapi-subscriptions/.meshrc.yml +++ b/examples/openapi-subscriptions/.meshrc.yml @@ -5,9 +5,11 @@ sources: source: ./openapi.yml baseUrl: http://localhost:4001 +documents: + - ./example-queries/**/*.graphql + serve: port: 4000 handlers: - path: /callback pubsubTopic: http://localhost:4000/callback - exampleQuery: ./example-queries/**/*.graphql diff --git a/packages/cli/src/bin.ts b/packages/cli/src/bin.ts index da8984e353876..747b1cf8d8cf1 100644 --- a/packages/cli/src/bin.ts +++ b/packages/cli/src/bin.ts @@ -4,4 +4,4 @@ import { handleFatalError } from './handleFatalError'; graphqlMesh() .then(() => {}) - .catch(e => handleFatalError(e, new DefaultLogger('Mesh'))); + .catch(e => handleFatalError(e, new DefaultLogger('πŸ•ΈοΈ'))); diff --git a/packages/cli/src/commands/serve/serve.ts b/packages/cli/src/commands/serve/serve.ts index d0c3ec2ee3185..26780f1b674b9 100644 --- a/packages/cli/src/commands/serve/serve.ts +++ b/packages/cli/src/commands/serve/serve.ts @@ -21,7 +21,7 @@ import { MeshInstance } from '@graphql-mesh/runtime'; import { handleFatalError } from '../../handleFatalError'; import open from 'open'; import { useServer } from 'graphql-ws/lib/use/ws'; -import { env } from 'process'; +import { env, on as processOn } from 'process'; import { YamlConfig, Logger } from '@graphql-mesh/types'; import { Source } from '@graphql-tools/utils'; import { inspect } from 'util'; @@ -37,19 +37,15 @@ export interface ServeMeshOptions { argsPort?: number; } +const terminateEvents = ['SIGINT', 'SIGTERM']; + +function registerTerminateHandler(callback: (eventName: string) => void) { + for (const eventName of terminateEvents) { + processOn(eventName, () => callback(eventName)); + } +} + export async function serveMesh({ baseDir, argsPort, getBuiltMesh, logger, rawConfig, documents }: ServeMeshOptions) { - logger.info(`Generating Mesh schema...`); - let readyFlag = false; - - const mesh$ = getBuiltMesh() - .then(mesh => { - readyFlag = true; - if (!fork) { - logger.info(`πŸ•ΈοΈ => Serving GraphQL Mesh: ${serverUrl}`); - } - return mesh; - }) - .catch(e => handleFatalError(e, logger)); const { fork, port: configPort, @@ -71,10 +67,25 @@ export async function serveMesh({ baseDir, argsPort, getBuiltMesh, logger, rawCo if (isMaster && fork) { const forkNum = fork > 1 ? fork : cpus().length; for (let i = 0; i < forkNum; i++) { - clusterFork(); + const worker = clusterFork(); + registerTerminateHandler(eventName => worker.kill(eventName)); } logger.info(`Serving GraphQL Mesh: ${serverUrl} in ${forkNum} forks`); } else { + logger.info(`Generating Mesh schema...`); + let readyFlag = false; + const mesh$ = getBuiltMesh() + .then(mesh => { + readyFlag = true; + logger.info(`Serving GraphQL Mesh: ${serverUrl}`); + registerTerminateHandler(eventName => { + const eventLogger = logger.child(`${eventName}πŸ’€`); + eventLogger.info(`Destroying GraphQL Mesh`); + mesh.destroy(); + }); + return mesh; + }) + .catch(e => handleFatalError(e, logger)); const app = express(); app.set('trust proxy', 'loopback'); let httpServer: Server; @@ -89,6 +100,18 @@ export async function serveMesh({ baseDir, argsPort, getBuiltMesh, logger, rawCo httpServer = createHTTPServer(app); } + registerTerminateHandler(eventName => { + const eventLogger = logger.child(`${eventName}πŸ’€`); + eventLogger.debug(`Stopping HTTP Server`); + httpServer.close(error => { + if (error) { + eventLogger.debug(`HTTP Server couldn't be stopped: ${error.message}`); + } else { + eventLogger.debug(`HTTP Server has been stopped`); + } + }); + }); + if (corsConfig) { app.use(cors(corsConfig)); } @@ -105,7 +128,19 @@ export async function serveMesh({ baseDir, argsPort, getBuiltMesh, logger, rawCo server: httpServer, }); - useServer( + registerTerminateHandler(eventName => { + const eventLogger = logger.child(`${eventName}πŸ’€`); + eventLogger.debug(`Stopping WebSocket Server`); + wsServer.close(error => { + if (error) { + eventLogger.debug(`WebSocket Server couldn't be stopped: ${error.message}`); + } else { + eventLogger.debug(`WebSocket Server has been stopped`); + } + }); + }); + + const { dispose: stopGraphQLWSServer } = useServer( { schema: () => mesh$.then(({ schema }) => schema), execute: args => @@ -132,6 +167,19 @@ export async function serveMesh({ baseDir, argsPort, getBuiltMesh, logger, rawCo wsServer ); + registerTerminateHandler(eventName => { + const eventLogger = logger.child(`${eventName}πŸ’€`); + eventLogger.debug(`Stopping GraphQL WS`); + Promise.resolve() + .then(() => stopGraphQLWSServer()) + .then(() => { + eventLogger.debug(`GraphQL WS has been stopped`); + }) + .catch(error => { + eventLogger.debug(`GraphQL WS couldn't be stopped: ${error.message}`); + }); + }); + const pubSubHandler: RequestHandler = (req, _res, next) => { Promise.resolve().then(async () => { const { pubsub } = await mesh$; diff --git a/packages/cli/src/handleFatalError.ts b/packages/cli/src/handleFatalError.ts index 3a9479f5ad40a..05cb4fcbf529d 100644 --- a/packages/cli/src/handleFatalError.ts +++ b/packages/cli/src/handleFatalError.ts @@ -3,7 +3,7 @@ import { env, exit } from 'process'; import { inspect } from 'util'; import { DefaultLogger } from '@graphql-mesh/utils'; -export function handleFatalError(e: Error, logger: Logger = new DefaultLogger('Mesh')): any { +export function handleFatalError(e: Error, logger: Logger = new DefaultLogger('πŸ•ΈοΈ')): any { const errorText = e.message; logger.error(errorText); if (env.DEBUG) { diff --git a/packages/cli/src/index.ts b/packages/cli/src/index.ts index 59f1b73ff706e..31cffc62f3f47 100644 --- a/packages/cli/src/index.ts +++ b/packages/cli/src/index.ts @@ -28,7 +28,7 @@ const SERVE_COMMAND_WARNING = export async function graphqlMesh() { let baseDir = cwd(); - let logger = new DefaultLogger('Mesh'); + let logger = new DefaultLogger('πŸ•ΈοΈ'); return yargs(hideBin(process.argv)) .help() .option('r', { @@ -79,11 +79,12 @@ export async function graphqlMesh() { const meshConfig = await findAndParseConfig({ dir: baseDir, }); + logger = meshConfig.logger; const serveMeshOptions: ServeMeshOptions = { baseDir, argsPort: args.port, getBuiltMesh: () => getMesh(meshConfig), - logger: meshConfig.logger, + logger: meshConfig.logger.child('Server'), rawConfig: meshConfig.config, documents: meshConfig.documents, }; @@ -98,8 +99,7 @@ export async function graphqlMesh() { ); await customServerHandler(serveMeshOptions); } else { - const result = await serveMesh(serveMeshOptions); - logger = result.logger; + await serveMesh(serveMeshOptions); } } catch (e) { handleFatalError(e, logger); @@ -126,12 +126,13 @@ export async function graphqlMesh() { const mainModule = join(builtMeshArtifactsPath, 'index.js'); const builtMeshArtifacts = await import(mainModule).then(m => m.default || m); const getMeshOptions: GetMeshOptions = await builtMeshArtifacts.getMeshOptions(); + logger = getMeshOptions.logger; const rawConfig: YamlConfig.Config = builtMeshArtifacts.rawConfig; const serveMeshOptions: ServeMeshOptions = { baseDir, argsPort: args.port, getBuiltMesh: () => getMesh(getMeshOptions), - logger: getMeshOptions.logger, + logger: getMeshOptions.logger.child('Server'), rawConfig: builtMeshArtifacts.rawConfig, documents: builtMeshArtifacts.documentsInSDL.map((documentSdl: string, i: number) => ({ rawSDL: documentSdl, diff --git a/packages/config/src/utils.ts b/packages/config/src/utils.ts index fa334ba0b3e8e..a8bb54a9ae1a4 100644 --- a/packages/config/src/utils.ts +++ b/packages/config/src/utils.ts @@ -190,10 +190,10 @@ export async function resolveLogger( code: '', }; } - const logger = new DefaultLogger('Mesh'); + const logger = new DefaultLogger('πŸ•ΈοΈ'); return { logger, importCode: `import { DefaultLogger } from '@graphql-mesh/utils';`, - code: `const logger = new DefaultLogger('Mesh');`, + code: `const logger = new DefaultLogger('πŸ•ΈοΈ');`, }; } diff --git a/packages/handlers/neo4j/src/index.ts b/packages/handlers/neo4j/src/index.ts index 1c867a9060b74..44a4d5573e549 100644 --- a/packages/handlers/neo4j/src/index.ts +++ b/packages/handlers/neo4j/src/index.ts @@ -32,7 +32,17 @@ export default class Neo4JHandler implements MeshHandler { logger: (level, message) => this.logger[level](message), }, }); - this.pubsub.subscribe('destroy', () => this.driver.close()); + this.pubsub.subscribe('destroy', () => { + this.logger.debug('Closing Neo4j'); + this.driver + .close() + .then(() => { + this.logger.debug('Neo4j has been closed'); + }) + .catch(error => { + this.logger.debug(`Neo4j couldn't be closed: ${error.message}`); + }); + }); } return this.driver; } diff --git a/packages/handlers/postgraphile/src/index.ts b/packages/handlers/postgraphile/src/index.ts index 7fda6a3ea75e5..552a7c410c9aa 100644 --- a/packages/handlers/postgraphile/src/index.ts +++ b/packages/handlers/postgraphile/src/index.ts @@ -64,7 +64,10 @@ export default class PostGraphileHandler implements MeshHandler { }); } - this.pubsub.subscribe('destroy', () => pgPool.end()); + this.pubsub.subscribe('destroy', () => { + this.logger.debug('Destroying PostgreSQL pool'); + pgPool.end(); + }); const cacheKey = this.name + '_introspection.json'; diff --git a/packages/runtime/src/get-mesh.ts b/packages/runtime/src/get-mesh.ts index 7fdaff3ac89c4..2603148c7ec3c 100644 --- a/packages/runtime/src/get-mesh.ts +++ b/packages/runtime/src/get-mesh.ts @@ -58,9 +58,9 @@ export interface MeshInstance { export async function getMesh(options: GetMeshOptions): Promise { const rawSources: RawSourceOutput[] = []; - const { pubsub, cache, logger = new DefaultLogger('Mesh') } = options; + const { pubsub, cache, logger = new DefaultLogger('πŸ•ΈοΈ') } = options; - const getMeshLogger = logger.child('getMesh/runtime'); + const getMeshLogger = logger.child('GetMesh'); getMeshLogger.debug(`Getting subschemas from source handlers`); await Promise.all( options.sources.map(async apiSource => { @@ -285,7 +285,7 @@ export async function getMesh(options: GetMeshOptions): Promise { return context; } - const executionLogger = logger.child(`meshExecute`); + const executionLogger = logger.child(`Execute`); async function meshExecute( document: GraphQLOperation, variableValues?: TVariables, diff --git a/packages/types/src/index.ts b/packages/types/src/index.ts index 8551d99b993ea..860a1b3250798 100644 --- a/packages/types/src/index.ts +++ b/packages/types/src/index.ts @@ -141,7 +141,7 @@ export type ImportFn = (moduleId: string) => Promise; export type SyncImportFn = (moduleId: string) => T; export type Logger = { - name: string; + name?: string; log: (message: string) => void; warn: (message: string) => void; info: (message: string) => void; diff --git a/packages/utils/src/logger.ts b/packages/utils/src/logger.ts index b11f399697b3c..072ef042219a6 100644 --- a/packages/utils/src/logger.ts +++ b/packages/utils/src/logger.ts @@ -9,9 +9,10 @@ const debugColor = chalk.magenta; const titleBold = chalk.bold; export class DefaultLogger implements Logger { - constructor(public name: string) {} + constructor(public name?: string) {} log(message: string) { - return console.log(`${titleBold(this.name)}: ${message}`); + const finalMessage = this.name ? `${titleBold(this.name)}: ${message}` : message; + return console.log(finalMessage); } warn(message: string) { @@ -27,12 +28,12 @@ export class DefaultLogger implements Logger { } debug(message: string) { - if (env.DEBUG) { + if ((env.DEBUG && env.DEBUG === '1') || this.name.includes(env.DEBUG)) { return this.log(debugColor(message)); } } child(name: string): Logger { - return new DefaultLogger(`${this.name} - ${name}`); + return new DefaultLogger(this.name ? `${this.name} - ${name}` : name); } }