Merge #336 always use custom logger if given

Author: justinmk

CHANGELOG.md

@@ -5,6 +5,7 @@
 - fix: console.log() writes to RPC channel #202 #329
 - feat: eliminate `which` dependency
 - feat: improve logs + error messages
+- fix: always use custom logger if one is given
 
 ## [5.0.1](https://github.com/neovim/node-client/compare/v4.11.0...v5.0.1) (2024-03-01)
 

packages/integration-tests/src/factory.test.ts

@@ -1,11 +1,33 @@
 /* eslint-env jest */
-import { NvimPlugin, loadPlugin } from 'neovim';
+import { Neovim, NeovimClient, NvimPlugin, loadPlugin } from 'neovim';
+
+function getFakeNvimClient(): NeovimClient {
+  const logged: string[] = [];
+  let logger2 = {};
+  const fakeLog = (msg: any) => {
+    logged.push(msg);
+    return logger2;
+  };
+  logger2 = {
+    info: fakeLog,
+    warn: fakeLog,
+    debug: fakeLog,
+    error: fakeLog,
+  };
+  return {
+    logger: logger2 as any,
+  } as NeovimClient;
+}
 
 describe('Plugin Factory (used by host)', () => {
   let pluginObj: NvimPlugin;
 
   beforeEach(() => {
-    pluginObj = loadPlugin('@neovim/example-plugin', null);
+    const p = loadPlugin('@neovim/example-plugin', getFakeNvimClient());
+    if (!p) {
+      throw new Error();
+    }
+    pluginObj = p;
   });
 
   it('should collect the specs from a plugin file', () => {
@@ -58,21 +80,28 @@ describe('Plugin Factory (used by host)', () => {
   });
 
   it('loads plugin with instance of nvim API', () => {
-    const nvim = {};
+    const nvim = getFakeNvimClient();
     const plugin = loadPlugin('@neovim/example-plugin', nvim);
-    expect(plugin.nvim).toBe(nvim);
+    expect(plugin?.nvim).toBe(nvim);
   });
 
   it('returns null on invalid module', () => {
-    expect(loadPlugin('/asdlfjka/fl', {}, {})).toBeNull();
+    expect(loadPlugin('/asdlfjka/fl', {} as Neovim, {})).toBeNull();
   });
 });
 
 describe('Plugin Factory (decorator api)', () => {
   let pluginObj: NvimPlugin;
 
   beforeEach(() => {
-    pluginObj = loadPlugin('@neovim/example-plugin-decorators', null);
+    const p = loadPlugin(
+      '@neovim/example-plugin-decorators',
+      getFakeNvimClient()
+    );
+    if (!p) {
+      throw new Error();
+    }
+    pluginObj = p;
   });
 
   it('should collect the specs from a plugin file', () => {
@@ -123,21 +152,21 @@ describe('Plugin Factory (decorator api)', () => {
   });
 
   it('loads plugin with instance of nvim API', () => {
-    const nvim = {} as any;
+    const nvim = getFakeNvimClient();
     const plugin = loadPlugin('@neovim/example-plugin-decorators', nvim, {});
-    expect(plugin.nvim).toBe(nvim);
+    expect(plugin!.nvim).toBe(nvim);
   });
 
   it('cannot call illegal process functions', () => {
-    const nvim = {} as any;
+    const nvim = getFakeNvimClient();
     const plugin = loadPlugin('@neovim/example-plugin-decorators', nvim, {});
-    expect(plugin.functions.Illegal.fn).toThrow();
+    expect(plugin!.functions.Illegal.fn).toThrow();
   });
 
   it('can read process.umask()', () => {
-    const nvim = {} as any;
+    const nvim = getFakeNvimClient();
     const plugin = loadPlugin('@neovim/example-plugin-decorators', nvim, {});
-    expect(() => plugin.functions.Umask.fn()).not.toThrow();
-    expect(plugin.functions.Umask.fn()).toBeDefined();
+    expect(() => plugin!.functions.Umask.fn()).not.toThrow();
+    expect(plugin!.functions.Umask.fn()).toBeDefined();
   });
 });

packages/neovim/bin/cli.js

@@ -1,6 +1,5 @@
 #!/usr/bin/env node
 const { Host } = require('../lib/host');
-const { logger } = require('../lib/utils/logger');
 const { spawnSync } = require('child_process');
 
 // node <current script> <rest of args>
@@ -35,9 +34,9 @@ try {
   const host = new Host(args);
   host.start({ proc: process });
 } catch (err) {
-  logger.error(err);
+  process.stderr.write(`failed to start Nvim plugin host: ${err.name}: ${err.message}\n`);
 }
 
 process.on('unhandledRejection', (reason, p) => {
-  logger.info('Unhandled Rejection at:', p, 'reason:', reason);
+  process.stderr.write(`Unhandled Rejection at: ${p} reason: ${reason}\n`);
 });

packages/neovim/src/api/Base.ts

@@ -1,7 +1,7 @@
 import { EventEmitter } from 'node:events';
 
 import { Transport } from '../utils/transport';
-import { Logger } from '../utils/logger';
+import { Logger, getLogger } from '../utils/logger';
 import { VimValue } from '../types/VimValue';
 
 export interface BaseConstructorOptions {
@@ -50,7 +50,7 @@ export class BaseApi extends EventEmitter {
     this.setTransport(transport);
     this.data = data;
     // eslint-disable-next-line global-require, @typescript-eslint/no-var-requires
-    this.logger = logger || require('../utils/logger').logger;
+    this.logger = logger || getLogger();
     this.client = client;
 
     if (metadata) {
@@ -73,7 +73,7 @@ export class BaseApi extends EventEmitter {
   [DO_REQUEST] = (name: string, args: any[] = []): Promise<any> =>
     new Promise((resolve, reject) => {
       this.transport.request(name, args, (err: any, res: any) => {
-        this.logger.debug(`response -> neovim.api.${name}: ${res}`);
+        this.logger.debug(`response -> ${name}: ${res}`);
         if (err) {
           reject(new Error(`${name}: ${err[1]}`));
         } else {
@@ -82,22 +82,18 @@ export class BaseApi extends EventEmitter {
       });
     });
 
-  async asyncRequest(
-    name: string,
-    args: any[] = [],
-    stack: string | undefined = undefined
-  ): Promise<any> {
+  async asyncRequest(name: string, args: any[] = []): Promise<any> {
     // `this._isReady` is undefined in ExtType classes (i.e. Buffer, Window, Tabpage)
     // But this is just for Neovim API, since it's possible to call this method from Neovim class
     // before transport is ready.
     // Not possible for ExtType classes since they are only created after transport is ready
     await this._isReady;
 
-    this.logger.debug(`request -> neovim.api.${name}`);
+    this.logger.debug(`request -> ${name}`);
 
     return this[DO_REQUEST](name, args).catch(err => {
+      // XXX: Get a `*.ts stacktrace. If we re-throw `err` we get a `*.js` trace. tsconfig issue?
       const newError = new Error(err.message);
-      newError.stack = stack;
       this.logger.error(
         `failed request to "%s": %s: %s`,
         name,
@@ -109,12 +105,7 @@ export class BaseApi extends EventEmitter {
   }
 
   request(name: string, args: any[] = []): Promise<any> {
-    // Dummy error, to get stacktrace.
-    const error = new Error(
-      `failed request to "${name}" (see $NVIM_NODE_LOG_FILE for details, if it was set)`
-    );
-
-    return this.asyncRequest(name, args, error.stack);
+    return this.asyncRequest(name, args);
   }
 
   _getArgsByPrefix(...args: any[]): any[] {
@@ -169,7 +160,7 @@ export class BaseApi extends EventEmitter {
   // TODO: Is this necessary?
   /** `request` is basically the same except you can choose to wait forpromise to be resolved */
   notify(name: string, args: any[]): void {
-    this.logger.debug(`notify -> neovim.api.${name}`);
+    this.logger.debug(`notify -> ${name}`);
     this.transport.notify(name, args);
   }
 }

packages/neovim/src/api/client.ts

@@ -1,7 +1,7 @@
 /**
  * Handles attaching transport
  */
-import { logger } from '../utils/logger';
+import { Logger } from '../utils/logger';
 import { Transport } from '../utils/transport';
 import { VimValue } from '../types/VimValue';
 import { Neovim } from './Neovim';
@@ -18,7 +18,7 @@ export class NeovimClient extends Neovim {
 
   private attachedBuffers: Map<string, Map<string, Function[]>> = new Map();
 
-  constructor(options: { transport?: Transport; logger?: typeof logger } = {}) {
+  constructor(options: { transport?: Transport; logger?: Logger } = {}) {
     // Neovim has no `data` or `metadata`
     super({
       logger: options.logger,

packages/neovim/src/attach/attach.ts

@@ -2,7 +2,7 @@ import { createConnection } from 'node:net';
 import * as child from 'node:child_process';
 
 import { NeovimClient } from '../api/client';
-import { Logger } from '../utils/logger';
+import { Logger, getLogger } from '../utils/logger';
 
 export interface Attach {
   reader?: NodeJS.ReadableStream;
@@ -38,7 +38,7 @@ export function attach({
 
   if (writer && reader) {
     // eslint-disable-next-line global-require, @typescript-eslint/no-var-requires
-    const loggerInstance = options.logger || require('../utils/logger').logger; // lazy load to winston only if needed
+    const loggerInstance = options.logger || getLogger(); // lazy load to winston only if needed
     const neovim = new NeovimClient({ logger: loggerInstance });
     neovim.attach({
       writer,

packages/neovim/src/host/NvimPlugin.test.ts

@@ -1,27 +1,37 @@
 /* eslint-env jest */
+import { getFakeNvimClient } from '../testUtil';
 import { callable, NvimPlugin } from './NvimPlugin';
 
 describe('NvimPlugin', () => {
   it('should initialise variables', () => {
-    const plugin = new NvimPlugin('/tmp/filename', () => {}, {});
+    const fakeNvimClient = getFakeNvimClient();
+    const plugin = new NvimPlugin('/tmp/filename', () => {}, fakeNvimClient);
 
     expect(plugin.filename).toEqual('/tmp/filename');
-    expect(plugin.nvim).toEqual({});
+    expect(plugin.nvim).toEqual(fakeNvimClient);
     expect(plugin.dev).toBe(false);
     expect(Object.keys(plugin.autocmds)).toHaveLength(0);
     expect(Object.keys(plugin.commands)).toHaveLength(0);
     expect(Object.keys(plugin.functions)).toHaveLength(0);
   });
 
   it('should set dev options when you call setOptions', () => {
-    const plugin = new NvimPlugin('/tmp/filename', () => {}, {});
+    const plugin = new NvimPlugin(
+      '/tmp/filename',
+      () => {},
+      getFakeNvimClient()
+    );
     plugin.setOptions({ dev: true });
     expect(plugin.dev).toBe(true);
     expect(plugin.shouldCacheModule).toBe(false);
   });
 
   it('should store registered autocmds', () => {
-    const plugin = new NvimPlugin('/tmp/filename', () => {}, {});
+    const plugin = new NvimPlugin(
+      '/tmp/filename',
+      () => {},
+      getFakeNvimClient()
+    );
     const fn = () => {};
     const opts = { pattern: '*' };
     const spec = {
@@ -36,7 +46,11 @@ describe('NvimPlugin', () => {
   });
 
   it('should store registered commands', () => {
-    const plugin = new NvimPlugin('/tmp/filename', () => {}, {});
+    const plugin = new NvimPlugin(
+      '/tmp/filename',
+      () => {},
+      getFakeNvimClient()
+    );
     const fn = () => {};
     const opts = { sync: true };
     const spec = {
@@ -51,7 +65,11 @@ describe('NvimPlugin', () => {
   });
 
   it('should store registered functions', () => {
-    const plugin = new NvimPlugin('/tmp/filename', () => {}, {});
+    const plugin = new NvimPlugin(
+      '/tmp/filename',
+      () => {},
+      getFakeNvimClient()
+    );
     const fn = () => {};
     const opts = { sync: true };
     const spec = {
@@ -66,7 +84,11 @@ describe('NvimPlugin', () => {
   });
 
   it('should not add autocmds with no pattern option', () => {
-    const plugin = new NvimPlugin('/tmp/filename', () => {}, {});
+    const plugin = new NvimPlugin(
+      '/tmp/filename',
+      () => {},
+      getFakeNvimClient()
+    );
     plugin.registerAutocmd('BufWritePre', () => {}, { pattern: '' });
     expect(Object.keys(plugin.autocmds)).toHaveLength(0);
   });
@@ -82,7 +104,11 @@ describe('NvimPlugin', () => {
     const thisObj = {};
     expect(callable([thisObj, fn])()).toBe(thisObj);
 
-    const plugin = new NvimPlugin('/tmp/filename', () => {}, {});
+    const plugin = new NvimPlugin(
+      '/tmp/filename',
+      () => {},
+      getFakeNvimClient()
+    );
     const obj = {
       func: jest.fn(function () {
         return this;
@@ -97,13 +123,21 @@ describe('NvimPlugin', () => {
   });
 
   it('should not register commands with incorrect callable arguments', () => {
-    const plugin = new NvimPlugin('/tmp/filename', () => {}, {});
+    const plugin = new NvimPlugin(
+      '/tmp/filename',
+      () => {},
+      getFakeNvimClient()
+    );
     plugin.registerCommand('MyCommand', [], {});
     expect(Object.keys(plugin.commands)).toHaveLength(0);
   });
 
   it('should return specs for registered commands', () => {
-    const plugin = new NvimPlugin('/tmp/filename', () => {}, {});
+    const plugin = new NvimPlugin(
+      '/tmp/filename',
+      () => {},
+      getFakeNvimClient()
+    );
     const fn = () => {};
     const aOpts = { pattern: '*' };
     const aSpec = {
@@ -136,7 +170,11 @@ describe('NvimPlugin', () => {
   });
 
   it('should handle requests for registered commands', async () => {
-    const plugin = new NvimPlugin('/tmp/filename', () => {}, {});
+    const plugin = new NvimPlugin(
+      '/tmp/filename',
+      () => {},
+      getFakeNvimClient()
+    );
     const fn = arg => arg;
 
     plugin.registerAutocmd('BufWritePre', fn, { pattern: '*', sync: true });
@@ -155,7 +193,11 @@ describe('NvimPlugin', () => {
   });
 
   it('should throw on unknown request', () => {
-    const plugin = new NvimPlugin('/tmp/filename', () => {}, {});
+    const plugin = new NvimPlugin(
+      '/tmp/filename',
+      () => {},
+      getFakeNvimClient()
+    );
     expect.assertions(1);
     plugin.handleRequest('BufWritePre *', 'autocmd', [true]).catch(err => {
       expect(err).toEqual(