fix(logger): write $ALLOW_CONSOLE logs to stderr

CHANGELOG.md

@@ -2,7 +2,8 @@
 
 ## [5.6.0](https://github.com/neovim/node-client/compare/v5.5.0...v5.6.0)
 
-- TODO
+- fix(logger): `$ALLOW_CONSOLE` writes logs to stderr instead of stdout, so it no longer breaks the
+  stdio RPC channel. #343
 
 ## [5.5.0](https://github.com/neovim/node-client/compare/v5.4.0...v5.5.0)
 

README.md

@@ -37,8 +37,8 @@ The `neovim` package provides these functions:
   - Best practice in any case is to use the `logger` available from the `NeovimClient` returned by
     `attach()`, instead of `console` logging functions.
 - Set the `$NVIM_NODE_LOG_FILE` env var to (also) write logs to a file.
-- Set the `$ALLOW_CONSOLE` env var to (also) write logs to stdout. **This will break any (stdio) RPC
-  channel** because logs written to stdout are invalid RPC messages.
+- Set the `$ALLOW_CONSOLE` env var to (also) write logs to stderr (not stdout, because that would
+  break the stdio RPC channel).
 
 ### Quickstart: connect to Nvim
 
@@ -56,10 +56,7 @@ Following is a complete, working example.
    ALLOW_CONSOLE=1 node demo.mjs
    ```
 
-   - `$ALLOW_CONSOLE` env var must be set, because logs are normally not printed to stdout.
-     - Note: `$ALLOW_CONSOLE` is only for demo purposes. It cannot be used for remote plugins or
-       whenever stdio is an RPC channel, because writing logs to stdout would break the RPC
-       channel.
+   - `$ALLOW_CONSOLE` env var must be set, because logs are normally not printed to the terminal.
    - Script:
 
    ```js

packages/neovim/src/utils/logger.test.ts

@@ -0,0 +1,35 @@
+import { spawnSync } from 'node:child_process';
+import * as path from 'node:path';
+import expect from 'expect';
+
+describe('logger', () => {
+  it('$ALLOW_CONSOLE writes to stderr, not stdout', () => {
+    // Needs a new process: the logger is a singleton configured from env vars at load-time.
+    const script = [
+      "const logger = require('./src/utils/logger').getLogger();",
+      "logger.error('test-error');",
+      "logger.warn('test-warn');",
+      "logger.info('test-info');",
+      "logger.debug('test-debug');",
+      "console.log('test-console-log');",
+    ].join('\n');
+    const env: NodeJS.ProcessEnv = {
+      ...process.env,
+      TS_NODE_TRANSPILE_ONLY: 'true',
+      ALLOW_CONSOLE: '1',
+      NVIM_NODE_LOG_LEVEL: 'debug',
+    };
+    delete env.NVIM_NODE_LOG_FILE;
+    const result = spawnSync(process.execPath, ['-r', 'ts-node/register', '-e', script], {
+      cwd: path.resolve(__dirname, '../..'),
+      env,
+      encoding: 'utf8',
+    });
+
+    expect(result.status).toEqual(0);
+    expect(result.stdout).toEqual('');
+    for (const msg of ['test-error', 'test-warn', 'test-info', 'test-debug', 'test-console-log']) {
+      expect(result.stderr).toContain(msg);
+    }
+  }).timeout(30000);
+});

packages/neovim/src/utils/logger.ts

@@ -47,6 +47,8 @@ function setupWinstonLogger(): Logger {
     logger.add(
       new winston.transports.Console({
         format: getFormat(true),
+        // Write all levels to stderr: stdout may be the (stdio) RPC channel.
+        stderrLevels: Object.keys(winston.config.npm.levels),
       })
     );
   }