fix: crash on receiving an LSP message in "stream" mode

Don't write log messages to stdout in "stream" mode. stdout is reserved
for communicating with the LSP client in the "stream" mode. Write all
types of log messages to stderr.

Fixes LSP server crashing on the first message it receives (or maybe
LSP client closing it because it received an invalid response).

Also:
 - the callback to socket.write() was always logging the "err" parameter
   even if there was undefined which caused spurious lines in the
   console. Only actually log that if "err" is truthy.
 - Avoid too many newlines at the end of the log message as that also
   causes spurious empty lines in the log and the console.
 - Gracefully handle the case when the response for "workspace/configuration"
   returns a null value. Those configuration options have sane defaults
   and don't need to be present.
 - The Logger._stream property was removed as it was unused.

Resolves #1708

CONTRIBUTING.md

@@ -25,7 +25,7 @@ Our commit messages are linted by `commitlint` following the angular changelog c
 
 You will need to include a type prefix for all commit messages. For example:
 
-`git commit -m 'fix: fix window undefined error in result viewer'
+`git commit -m 'fix: fix window undefined error in result viewer'`
 
 ### Type Prefixes
 

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

@@ -8,21 +8,24 @@
  */
 
 import { Logger as VSCodeLogger } from 'vscode-jsonrpc';
+import { DiagnosticSeverity } from 'vscode-languageserver';
 
 import * as fs from 'fs';
 import * as os from 'os';
 import { join } from 'path';
+import { Socket } from 'net';
 
 import {
   DIAGNOSTIC_SEVERITY,
   SeverityEnum,
   SEVERITY,
 } from 'graphql-language-service';
+
 export class Logger implements VSCodeLogger {
   _logFilePath: string;
-  _stream: fs.WriteStream | null;
+  _stderrOnly: boolean;
 
-  constructor(tmpDir?: string) {
+  constructor(tmpDir?: string, stderrOnly?: boolean) {
     const dir = join(tmpDir || os.tmpdir(), 'graphql-language-service-logs');
     try {
       if (!fs.existsSync(dir)) {
@@ -40,7 +43,7 @@ export class Logger implements VSCodeLogger {
       }-${getDateString()}.log`,
     );
 
-    this._stream = null;
+    this._stderrOnly = stderrOnly || false;
   }
 
   error(message: string): void {
@@ -64,15 +67,22 @@ export class Logger implements VSCodeLogger {
     const severity = DIAGNOSTIC_SEVERITY[severityKey];
     const pid = process.pid;
 
-    const logMessage = `${timestamp} [${severity}] (pid: ${pid}) graphql-language-service-usage-logs: ${message}\n\n`;
+    const stringMessage = String(message).trim();
+    const logMessage = `${timestamp} [${severity}] (pid: ${pid}) graphql-language-service-usage-logs: ${stringMessage}\n`;
     // write to the file in tmpdir
     fs.appendFile(this._logFilePath, logMessage, _error => {});
-    const processSt =
-      severity === DIAGNOSTIC_SEVERITY.Error ? process.stderr : process.stdout;
-    processSt.write(logMessage, err => {
-      console.error(err);
+    this._getOutputStream(severity).write(logMessage, err => {
+      err && console.error(err);
     });
   }
+
+  _getOutputStream(severity: DiagnosticSeverity): Socket {
+    if (this._stderrOnly || severity === DIAGNOSTIC_SEVERITY.Error) {
+      return process.stderr;
+    }
+
+    return process.stdout;
+  }
 }
 
 // function getUnixTime() {

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

@@ -206,14 +206,14 @@ export class MessageProcessor {
     const vscodeSettings = await this._connection.workspace.getConfiguration({
       section: 'vscode-graphql',
     });
-    if (settings.dotEnvPath) {
+    if (settings?.dotEnvPath) {
       require('dotenv').config({ path: settings.dotEnvPath });
     }
     this._settings = { ...settings, ...vscodeSettings };
     const rootDir = this._settings?.load?.rootDir || this._rootPath;
     this._rootPath = rootDir;
     this._loadConfigOptions = {
-      ...Object.keys(this._settings?.load).reduce((agg, key) => {
+      ...Object.keys(this._settings.load || []).reduce((agg, key) => {
         const value = this._settings.load[key];
         if (value === undefined || value === null) {
           delete agg[key];

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

@@ -0,0 +1,64 @@
+/**
+ *  Copyright (c) 2020 GraphQL Contributors
+ *  All rights reserved.
+ *
+ *  This source code is licensed under the license found in the
+ *  LICENSE file in the root directory of this source tree.
+ *
+ */
+
+import { tmpdir } from 'os';
+import { Logger } from '../Logger';
+
+describe('Logger', () => {
+  let mockedStdoutWrite: jest.SpyInstance = null;
+  let mockedStderrWrite: jest.SpyInstance = null;
+
+  beforeEach(async () => {
+    mockedStdoutWrite = jest
+      .spyOn(process.stdout, 'write')
+      .mockImplementation(() => true);
+    mockedStderrWrite = jest
+      .spyOn(process.stderr, 'write')
+      .mockImplementation(() => true);
+  });
+
+  afterEach(() => {
+    mockedStdoutWrite.mockReset();
+    mockedStderrWrite.mockReset();
+  });
+
+  it('logs to stdout', () => {
+    const logger = new Logger(tmpdir());
+    logger.log('log test');
+
+    expect(mockedStdoutWrite.mock.calls.length).toBe(1);
+    expect(mockedStdoutWrite.mock.calls[0][0]).toContain('log test');
+    expect(mockedStderrWrite.mock.calls.length).toBe(0);
+  });
+
+  it('logs to stderr', () => {
+    const logger = new Logger(tmpdir());
+    logger.error('error test');
+
+    expect(mockedStdoutWrite.mock.calls.length).toBe(0);
+    expect(mockedStderrWrite.mock.calls.length).toBe(1);
+    expect(mockedStderrWrite.mock.calls[0][0]).toContain('error test');
+  });
+
+  it('only writes to stderr with "stderrOnly" enabled', () => {
+    const stderrOnly = true;
+    const logger = new Logger(tmpdir(), stderrOnly);
+    logger.info('info test');
+    logger.warn('warn test');
+    logger.log('log test');
+    logger.error('error test');
+
+    expect(mockedStdoutWrite.mock.calls.length).toBe(0);
+    expect(mockedStderrWrite.mock.calls.length).toBe(4);
+    expect(mockedStderrWrite.mock.calls[0][0]).toContain('info test');
+    expect(mockedStderrWrite.mock.calls[1][0]).toContain('warn test');
+    expect(mockedStderrWrite.mock.calls[2][0]).toContain('log test');
+    expect(mockedStderrWrite.mock.calls[3][0]).toContain('error test');
+  });
+});

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

@@ -106,13 +106,15 @@ describe('MessageProcessor', () => {
       },
     };
   });
+
+  let getConfigurationReturnValue = {};
   // @ts-ignore
   messageProcessor._connection = {
     // @ts-ignore
     get workspace() {
       return {
         getConfiguration: async () => {
-          return [{}];
+          return [getConfigurationReturnValue];
         },
       };
     },
@@ -246,6 +248,15 @@ describe('MessageProcessor', () => {
     expect(result.diagnostics.length).toEqual(0);
   });
 
+  it('does not crash on null value returned in response to workspace configuration', async () => {
+    const previousConfigurationValue = getConfigurationReturnValue;
+    getConfigurationReturnValue = null;
+    await expect(
+      messageProcessor.handleDidChangeConfiguration(),
+    ).resolves.toStrictEqual({});
+    getConfigurationReturnValue = previousConfigurationValue;
+  });
+
   it('properly removes from the file cache with the didClose handler', async () => {
     await messageProcessor.handleDidCloseNotification(initialDocument);
 

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

@@ -148,9 +148,10 @@ const buildOptions = (options: ServerOptions): MappedServerOptions => {
 export default async function startServer(
   options: ServerOptions,
 ): Promise<void> {
-  const logger = new Logger(options.tmpDir);
-
   if (options && options.method) {
+    const stderrOnly = options.method === 'stream';
+    const logger = new Logger(options.tmpDir, stderrOnly);
+
     const finalOptions = buildOptions(options);
     let reader;
     let writer;