fix log level, keep things relevant

Author: acao

packages/graphql-language-service-server/src/Logger.ts

@@ -11,7 +11,48 @@ import { Logger as VSCodeLogger } from 'vscode-jsonrpc';
 import { Connection } from 'vscode-languageserver';
 
 export class Logger implements VSCodeLogger {
-  constructor(private _connection: Connection) {}
+  // TODO: allow specifying exact log level?
+  // for now this is to handle the debug setting
+  private logLevel: number;
+  constructor(
+    private _connection: Connection,
+    debug?: boolean,
+  ) {
+    this.logLevel = debug ? 1 : 0;
+    // first detect the debug flag on initialization
+    void (async () => {
+      try {
+        const config = await this._connection?.workspace?.getConfiguration(
+          'vscode-graphql',
+        );
+        const debugSetting = config?.get('debug');
+        if (debugSetting === true) {
+          this.logLevel = 1;
+        }
+        if (debugSetting === false || debugSetting === null) {
+          this.logLevel = 0;
+        }
+      } catch {
+        // ignore
+      }
+    })();
+    // then watch for it to change. doesn't require re-creating the logger!
+    this._connection?.onDidChangeConfiguration(config => {
+      const debugSetting =
+        config?.settings && config.settings['vscode-graphql']?.debug;
+      // if it's undefined, it's not being passed
+      if (debugSetting === undefined) {
+        return;
+      }
+      // if it's true, set it to 1, we will eventually do log levels properly
+      if (debugSetting === true) {
+        this.logLevel = 1;
+      }
+      if (debugSetting === false || debugSetting === null) {
+        this.logLevel = 0;
+      }
+    });
+  }
 
   error(message: string): void {
     this._connection.console.error(message);
@@ -26,7 +67,9 @@ export class Logger implements VSCodeLogger {
   }
 
   log(message: string): void {
-    this._connection.console.log(message);
+    if (this.logLevel > 0) {
+      this._connection.console.log(message);
+    }
   }
 }
 

packages/graphql-language-service-server/src/MessageProcessor.ts

@@ -255,8 +255,14 @@ export class MessageProcessor {
       const config = this._graphQLCache.getGraphQLConfig();
       if (config) {
         await this._cacheAllProjectFiles(config);
+        // TODO: per project lazy instantiation.
+        // we had it working before, but it seemed like it caused bugs
+        // which were caused by something else.
+        // thus. _isInitialized should be replaced with something like
+        // projectHasInitialized: (projectName: string) => boolean
         this._isInitialized = true;
         this._isGraphQLConfigMissing = false;
+        this._logger.info('GraphQL Language Server caches initialized');
       }
     } catch (err) {
       this._handleConfigError({ err });
@@ -387,9 +393,6 @@ export class MessageProcessor {
         // i think this is because if the file change is empty, it doesn't get parsed
         // TODO: this could be related to a bug in how we are calling didOpenOrSave in our tests
         // that doesn't reflect the real runtime behavior
-        // if (!text || text.length < 1) {
-        //   return { uri, diagnostics };
-        // }
 
         const { contents } = await this._parseAndCacheFile(
           uri,
@@ -963,8 +966,8 @@ export class MessageProcessor {
         await this._invalidateCache({ version, uri }, uri, contents);
         await this._updateObjectTypeDefinition(uri, contents, project);
       }
-    } catch {
-      //  this._logger.error(String(err));
+    } catch (err) {
+      this._logger.error(String(err));
     }
   }
   private async _cacheSchemaFile(
@@ -1158,8 +1161,19 @@ export class MessageProcessor {
       return Promise.all(
         Object.keys(config.projects).map(async projectName => {
           const project = config.getProject(projectName);
+
           await this._cacheSchemaFilesForProject(project);
-          await this._cacheDocumentFilesforProject(project);
+          if (project.documents?.length) {
+            await this._cacheDocumentFilesforProject(project);
+          } else {
+            this._logger.warn(
+              [
+                `No 'documents' config found for project: ${projectName}.`,
+                'Fragments and query documents cannot be detected.',
+                'LSP server will only perform some partial validation and SDL features.',
+              ].join('\n'),
+            );
+          }
         }),
       );
     }

packages/graphql-language-service-server/src/__tests__/Logger.test.ts

@@ -0,0 +1,73 @@
+import { Logger } from '../Logger';
+
+describe('Logger', () => {
+  const connection = {
+    console: {
+      error: jest.fn(),
+      warn: jest.fn(),
+      info: jest.fn(),
+      log: jest.fn(),
+    },
+    onDidChangeConfiguration: jest.fn(),
+    workspace: {
+      getConfiguration: jest.fn(),
+    },
+  };
+
+  beforeEach(() => {
+    jest.clearAllMocks();
+  });
+
+  it('should initialize with default log level, and ignore .log intentionally', () => {
+    const logger = new Logger(connection as any);
+    expect(logger).toBeDefined();
+    expect(connection.onDidChangeConfiguration).toHaveBeenCalledTimes(1);
+    expect(logger.logLevel).toBe(0);
+    logger.log('test');
+    expect(connection.console.log).toHaveBeenCalledTimes(0);
+  });
+
+  it('should initialize with default log level, then change to logging with new settings, then back when they are disabled', () => {
+    const logger = new Logger(connection as any);
+    expect(logger).toBeDefined();
+    expect(connection.onDidChangeConfiguration).toHaveBeenCalledTimes(1);
+    expect(logger.logLevel).toBe(0);
+    logger.log('test');
+    expect(connection.console.log).toHaveBeenCalledTimes(0);
+    connection.onDidChangeConfiguration.mock.calls[0][0]({
+      settings: { 'vscode-graphql': { debug: true } },
+    });
+    expect(logger.logLevel).toBe(1);
+    logger.log('test');
+    expect(connection.console.log).toHaveBeenCalledTimes(1);
+    connection.onDidChangeConfiguration.mock.calls[0][0]({
+      settings: { 'vscode-graphql': { debug: false } },
+    });
+    expect(logger.logLevel).toBe(0);
+    logger.log('test');
+    // and not a second time
+    expect(connection.console.log).toHaveBeenCalledTimes(1);
+  });
+
+  it('should not change log level when settings are not passed', () => {
+    const logger = new Logger(connection as any, true);
+    expect(logger).toBeDefined();
+    expect(connection.onDidChangeConfiguration).toHaveBeenCalledTimes(1);
+    expect(logger.logLevel).toBe(1);
+    logger.log('test');
+    expect(connection.console.log).toHaveBeenCalledTimes(1);
+    connection.onDidChangeConfiguration.mock.calls[0][0]({});
+    expect(logger.logLevel).toBe(1);
+    logger.log('test');
+    expect(connection.console.log).toHaveBeenCalledTimes(2);
+  });
+
+  it('should initialize with debug log level, and .log is visible now', () => {
+    const logger = new Logger(connection as any, true);
+    expect(logger).toBeDefined();
+    expect(connection.onDidChangeConfiguration).toHaveBeenCalledTimes(1);
+    expect(logger.logLevel).toBe(1);
+    logger.log('test');
+    expect(connection.console.log).toHaveBeenCalledTimes(1);
+  });
+});

packages/graphql-language-service-server/src/parsers/astro.ts

@@ -41,15 +41,15 @@ function parseAstro(source: string): ParseAstroResult {
   return { type: 'error', errors: ['Could not find frontmatter block'] };
 }
 
-export const astroParser: SourceParser = (text, _uri, _logger) => {
+export const astroParser: SourceParser = (text, uri, logger) => {
   const parseAstroResult = parseAstro(text);
   if (parseAstroResult.type === 'error') {
-    // logger.error(
-    //   `Could not parse the astro file at ${uri} to extract the graphql tags:`,
-    // );
-    // for (const error of parseAstroResult.errors) {
-    //   logger.error(String(error));
-    // }
+    logger.info(
+      `Could not parse the astro file at ${uri} to extract the graphql tags:`,
+    );
+    for (const error of parseAstroResult.errors) {
+      logger.info(String(error));
+    }
     return null;
   }
 

packages/graphql-language-service-server/src/parsers/babel.ts

@@ -11,26 +11,26 @@ export const babelParser = (text: string, plugins?: ParserPlugin[]) => {
   return parse(text, PARSER_OPTIONS);
 };
 
-export const ecmaParser: SourceParser = (text, _uri, _logger) => {
+export const ecmaParser: SourceParser = (text, uri, logger) => {
   try {
     return { asts: [babelParser(text, ['flow', 'flowComments'])] };
-  } catch {
-    // logger.error(
-    //   `Could not parse the JavaScript file at ${uri} to extract the graphql tags:`,
-    // );
-    // logger.error(String(error));
+  } catch (error) {
+    logger.info(
+      `Could not parse the JavaScript file at ${uri} to extract the graphql tags:`,
+    );
+    logger.info(String(error));
     return null;
   }
 };
 
-export const tsParser: SourceParser = (text, _uri, _logger) => {
+export const tsParser: SourceParser = (text, uri, logger) => {
   try {
     return { asts: [babelParser(text, ['typescript'])] };
-  } catch {
-    // logger.error(
-    //   `Could not parse the TypeScript file at ${uri} to extract the graphql tags:`,
-    // );
-    // logger.error(String(error));
+  } catch (error) {
+    logger.info(
+      `Could not parse the TypeScript file at ${uri} to extract the graphql tags:`,
+    );
+    logger.info(String(error));
     return null;
   }
 };

packages/graphql-language-service-server/src/parsers/svelte.ts

@@ -4,7 +4,7 @@ import { SourceMapConsumer } from 'source-map-js';
 import { Position, Range } from 'graphql-language-service';
 import type { RangeMapper, SourceParser } from './types';
 
-export const svelteParser: SourceParser = (text, uri, _logger) => {
+export const svelteParser: SourceParser = (text, uri, logger) => {
   const svelteResult = svelte2tsx(text, {
     filename: uri,
   });
@@ -35,11 +35,11 @@ export const svelteParser: SourceParser = (text, uri, _logger) => {
       asts: [babelParser(svelteResult.code, ['typescript'])],
       rangeMapper,
     };
-  } catch {
-    // logger.error(
-    //   `Could not parse the Svelte file at ${uri} to extract the graphql tags:`,
-    // );
-    // logger.error(String(error));
+  } catch (error) {
+    logger.info(
+      `Could not parse the Svelte file at ${uri} to extract the graphql tags:`,
+    );
+    logger.info(String(error));
     return null;
   }
 };

packages/graphql-language-service-server/src/parsers/vue.ts

@@ -45,16 +45,16 @@ export function parseVueSFC(source: string): ParseVueSFCResult {
   };
 }
 
-export const vueParser: SourceParser = (text, _uri, _logger) => {
+export const vueParser: SourceParser = (text, uri, logger) => {
   const asts = [];
   const parseVueSFCResult = parseVueSFC(text);
   if (parseVueSFCResult.type === 'error') {
-    // logger.error(
-    //   `Could not parse the vue file at ${uri} to extract the graphql tags:`,
-    // );
-    // for (const error of parseVueSFCResult.errors) {
-    //   logger.error(String(error));
-    // }
+    logger.info(
+      `Could not parse the vue file at ${uri} to extract the graphql tags:`,
+    );
+    for (const error of parseVueSFCResult.errors) {
+      logger.info(String(error));
+    }
     return null;
   }
 

packages/graphql-language-service-server/src/startServer.ts

@@ -102,6 +102,14 @@ export interface ServerOptions {
    * the temporary directory that the server writes to for logs and caching schema
    */
   tmpDir?: string;
+
+  /**
+   * debug mode
+   *
+   * same as with the client reference implementation, the debug setting controls logging output
+   * this allows all logger.info() messages to come through. by default, the highest level is warn
+   */
+  debug?: true;
 }
 
 /**
@@ -217,7 +225,7 @@ async function initializeHandlers({
   options,
 }: InitializerParams): Promise<Connection> {
   const connection = createConnection(reader, writer);
-  const logger = new Logger(connection);
+  const logger = new Logger(connection, options.debug);
 
   try {
     await addHandlers({ connection, logger, ...options });