fix: logging to debug console

[mohd-akram]

Fixes #1544

[neilenns]

I believe this was addressed with #2276

[mohd-akram]

@neilenns Not really. That PR causes everything to be displayed as an error. It would be better for the flag to be called something like logToInspector. This way it can be combined with this PR as a way to make this opt-in. forceConsole is poorly named IMO.

[neilenns]

That PR causes everything to be displayed as an error.

It logs using the appropriate console method based on the severity, either log(), warn(), or error(). Unless I'm missing something, it should cover exactly what was mentioned in issue #1544, and essentially puts the false value into the condition mentioned in the issue.

[mohd-akram]

I want to log everything to stderr and to the inspector with the correct severity. This cannot be done currently.

[Jimbly]

everything to stderr and to the inspector with the correct severity

That seems like a slightly odd specific combo, what's the need there, and is that a common case? I'd never expect something that goes to console.debug to end up in stderr myself, but if needed I believe that could be done currently by adding a custom log transport (since the built-in transport can already write all to stderr and nothing to inspector), which might be a simpler approach than extending the built-in transport?

[mohd-akram]

The typical Unix behavior of programs is to use stderr for logging and stdout for program output. If you log to stdout, that means you can no longer pipe your program's output to another program or save it to a file (since logs will end up there too).

That seems like a slightly odd specific combo.

Not very odd. To do it in Node.js:

const logger = new console.Console(process.stderr);

which might be a simpler approach than extending the built-in transport?

This PR is pretty simple, it's more about correct behavior. Rather than having the very specific consoleWarnLevels option, this PR provides a generic one, so all logging levels are preserved rather than just an arbitrary set of error/warn/log. Eg. inspector allows you to filter out verbose/debug, which you cannot do unless you log it as such.

[Jimbly]

Good points. Getting the verbose/debug levels to inspector is an especially good point, I see that the recently merged forceConsole PR does not call console.debug for debug-level logs, so that does seem like something lacking.

[DABH]

@Jimbly @neilenns Do you think that this PR is a superset of what #2276 does? (Like, should we have merged this PR instead of #2276?) Or are these complementary? If so, should we make any revisions to this one given that #2276 has been merged and released? I am open to merging stuff but relying on your guys' expertise and conclusions here

[neilenns]

I'm not an expert in this unfortunately.

The "does not call console.debug() for debug-level logs" comment, while valid, seems like a separate issue to the targeted change that #2276 did, which simply provided a flag to trigger existing code that logs messages using console methods.

[neilenns]

@DABH I looked at the code changes here. It's covering a related but different issue than what #2276 did, which simply made it possible to opt in to using console.* to log instead of stderr. The issue it is trying to address in the original code is a bug where there was no way to ever log using console.debug(). The best you could do was console.warn().

This PR uses the inspector APIs to log with the level specified, including logging debug when the level is debug, however it always does it in addition to writing to stderr etc. As @Jimbly mentions that doesn't seem appropriate.

If this PR were updated to move the changes into the else clause that's now triggered by forceConsole from #2276 then it might be ok.

At least that's my understanding while looking at all the related and this issue while drinking morning coffee.

[neilenns]

I agree with this proposal by the way, it really feels like the console transport is poorly named and should be called stdout or similar, with a separate transport that actually logs to the console using the method in this PR. Not sure how to pull that off though given the legacy naming of winston.transports.console and years of existing expectations of that transport.

[neilenns]

This needs to be added to index.d.ts as a property on ConsoleTransportOptions.

[neilenns]

@DABH To wrap this up neatly for you, here's what I believe needs to happen:

1. Merge Add forceConsole to ConsoleTransportOptions #2496 so the new property is available in TypeScript
2. Have @mohd-akram modify this PR so the use of inspector.console calls replace the existing console.* calls in the else clauses of the code
3. Make sure to include the new consoleLevels property introduced in this pr in the index.d.ts file
4. Merge this modified PR

A branch showing these variations is available here: https://github.com/neilenns/winston/tree/neilenns/2474-update. A branch of my project using these changes is available here: https://github.com/neilenns/streamdeck-trackaudio/tree/neilenns/try-winston. The relevant logger code looks like this:

import winston from "winston";

const Logger = winston.createLogger({
  level: "debug",
  transports: [
    new winston.transports.Console({ forceConsole: true }),
    new winston.transports.Console(),
  ],
});

export default Logger;

The result will be:

1. No more infinite recursion when doing console.log = mainLogger.log.bind(mainLogger);
2. The ability to directly target the console output using forceConsole
3. The ability to log to all messages to stderr and all message to the console with the appropriate level by using two instances of the Console transport, one with forceConsole set and one without
4. The ability for the inspector to see the actual level the message was logged at

Example output in VSCode:

{"level":"debug","message":"WebSocket connection closed","service":"trackAudio"}
{"level":"debug","message":"Attempting to reconnect...","service":"trackAudio"}

@mohd-akram @Jimbly can you please review my comments above and see if they align with your understanding?

[Jimbly]

modify this PR so the use of inspector.console calls replace the existing console.* calls in the else clauses of the code

Doing that and the new forceConsole option would cause no logs to get written to the console (terminal/stdout/stderr), only an inspector if you have one attached, so that option would at least be misnamed if anything.

Do you think that this PR is a superset of what #2276 does? (Like, should we have merged this PR instead of #2276?)

After my conversation with the author above yesterday, I'm leaning toward yes, this was probably the better solution that addresses the same problem, although (I swear I commented on this before, but I don't see it...) this PR as written enables writing to inspector by default, which is a significant change and will potentially be a breaking change for anyone who connects Node Inspector remotely to production servers that are very logging-heavy (will potentially almost immediately get a socket overflow and inspector or the target process will hang). So, it probably at least needs an option that doesn't write to inspector.

Personally/abstractly I like the proposal of splitting stdout and console (or more specifically inspector?) from the single "console" transport (but that's a much more involved change), but in the short term adding/fixing options on the one console transport is clearly a good solution.

[neilenns]

Putting this PR as a dedicated "inspector" transport seems reasonable? It would be a non-breaking change and wouldn't require adding yet more options to the existing console logger.

Then all that'd be required is fixing the infinite recursion option for console.*.

[neilenns]

I opened a dedicated PR to address the circular reference issue. I think that will resolve the issues exposed by the new flag, and this PR can be considered as a standalone feature request to support logging to inspector, presumably as a new transport instead of getting added to the existing Console transport.

[DABH]

Thank you so much for wrapping this up neatly for me 😅 This sounds like a good plan then. Let's try to use #2498 to fix the issues that @neilenns and @Jimbly have been discussing, and then if @mohd-akram wants to, they can redo this PR to make it some kind of separate Inspector transport (although then we should discuss whether that should be a default/built-in transport, or whether it should be one of the examples/, for instance). Re: #1836, I'm open to having two separate transports, but yeah, that would be a breaking change, so definitely a winston 4.0 kind of thing, but I'm not opposed.

[Jimbly]

Since the new forceConsole is off by default, as long as any "write to inspector" logic is added only under that flow, it wouldn't be a breaking change (forceConsole already writes to inspector via console).

It kinda seems like the cleanest/simplest solution from the user side is a single console transport with "stdio: both/stdout/stderr/none/mapping" (the existing and "inspector: yes/no/mapping" and the default (to avoid being a breaking change) is "both/no" or (to generally do what one expects/desires, as a change to defaults in a 4.0) is "both/yes". That being said, with the exception of the state need to both redirect all output to stderr and write to inspector as separate levels, that's almost what we've got with the forceConsole option (except, lacking the nice mapping from log levels to console levels like verbose in this PR).

[mohd-akram]

I don't think a separate inspector transport makes sense, since Console is the inspector transport. As I mentioned elsewhere, there already is a stream transport for purely stdout/stderr. With the new forceConsole option there is a strange difference in behavior - with it off, the eol option is respected and the inspector isn't written to. With it on, eol is ignored and the inspector is written to. A forceConsole option for a transport named Console makes no sense. If you look at the git history, that else branch was added only for runtimes that don't have console._stderr and not as a general mechanism. IMO the change should be reverted and this one should be incorporated which maintains the remaining behavior, and optionally a logToInspector option could be added to make this opt-in (this option can be removed in 4.x so that it is always on, and those who want stderr only should use the stream transport). If there is interest in this, I'll reopen this PR, otherwise I'm closing it for now. Thank you for all the comments.