-
Notifications
You must be signed in to change notification settings - Fork 440
process.stderr to use console.debug, with DEBUG level to stderr #4965
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Conversation
This is causing a Miniflare failure here:
so the question is whether this needs a compat flag / or can be done as a non-breaking change - if we want to go in this direction. |
@cloudflare/wrangler team.. if you can help with the above error |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
LGTM once the workers-sdk test failure is worked out
Note that one competing concern with this approach is that having |
Posted cloudflare/workers-sdk#10560 on Miniflare. I think this is the right way to go, just important to be explicit about tradeoffs. |
@guybedford I must admit that I don't not fully understand the changes and their implications in this PR. Could you please answer a few questions to help me understand (I think it's worth adding the answers/info in the PR description). IIUC the main change in this PR is that Maybe you can add a code snippet with the behavior before and after this PR to better explain how users will be affected. You say:
What do other runtimes do today (Node, Bun, Deno) do today?
This seems to indicate that other runtimes are doing differently. |
Absolutely.
Yes, exactly.
All JS runtimes print
Since our primary logging output is granular console entries and not raw terminal-style stdio, if we route The tradeoff is in aligning inspector logging and JSON logging with browser-style logging, where we effectively prioritise the browser conventions of avoiding noisy |
Conversely - if I am over-indexing on the importance of not creating |
Thanks for your answer, I'll unpack all of that tomorrow. I think it would also help to have a clear view about the differences from today, i.e.
That is what will be different
|
Today, unenv treats process.stdout and process.stderr as otherwise unused streams, so by default I believe they don't get output? It would be worth verifying though, perhaps there is a configuration that sends them somewhere? Would be good to verify as a first step indeed. |
Should we also check how unenv is handling |
I don't believe unenv alters console.debug, or otherwise uses it?
Consider for example a npm library using https://www.npmjs.com/package/debug. All debug output will be written to process.stderr. With unenv it would all be swallowed and invisible. With the new process implementation each line of debug info will be emitted individually as "error" console log types in the inspector and logs. Attaching to the worker logs would show a large number of errors in the logs, when these are not errors. We can either wait for this problem to hit us, or we can resolve the issue now. Up to you. |
I would prefer to handle this now that I have the context into memory. And again what I am looking for here is to really understand what the impacts will be for end users:
The fact that tests need to be updated with this PR tells me that the behavior has changed. How will this impact users. It might be easier to VC to discuss about that - feel free to pick a slot in my calendar when I'm available.
Using
unenv actually uses the tty streams which direct the output to I created a sample test app to verify: // logs "stdout"
process.stdout.write('stdout');
// logs "stderr"
process.stderr.write('stderr'); |
So it looks like this is not accurate, given the links to unenv from @vicb above? get stdout() {
return (this.#stdout ??= new WriteStream(1) as NodeJS.Process["stdout"]);
}
get stderr() {
return (this.#stderr ??= new WriteStream(2) as NodeJS.Process["stderr"]);
} and write(str: unknown, encoding?: unknown, cb?: unknown): boolean {
if (str instanceof Uint8Array) {
str = new TextDecoder().decode(str);
}
try {
console.log(str);
} catch {}
cb && typeof cb === "function" && cb();
return false;
} |
I think that with this PR's change (once the unenv polyfill is removed) the But equally if the current runtime set up is used (once the unenv polyfill is removed) would we start to see that Is the least breaking approach to send |
If I understand, though, in Wrangler we now use "structured logging" which I think means that none of this has any effect? Perhaps we need to make sure that these tests still pass with this PR? |
I note that we are not yet using structuredLogging in the Vite plugin and the Vitest integration: handleRuntimeStdio(stdout, stderr) {
const decoder = new TextDecoder();
stdout.forEach((data) => logger.info(decoder.decode(data)));
stderr.forEach((error) =>
logger.logWithLevel(LogLevel.ERROR, decoder.decode(error))
);
}, and function handleRuntimeStdio(stdout: Readable, stderr: Readable): void {
stdout.on("data", (chunk: Buffer) => {
process.stdout.write(chunk);
});
stderr.on("data", (chunk: Buffer) => {
const str = trimSymbolizerWarning(chunk.toString());
if (ignoreMessages.some((message) => str.includes(message))) {
return;
}
process.stderr.write(str);
}); So I expect that this PR would also be a breaking change for these. We could/should consider moving these over to use structuredLogging instead but then it would have the same concerns as Wrangler. |
I built workerd from this PR and then ran it locally with the changes in cloudflare/workers-sdk#10577.
and in the basic test (where log level is default) we get: without this change:
with this change
so the stderr message is disappearing, which concurs with our discussions above. And then with debug logging: without this change:
with this change
Note that the stderr message has moved from error level to debug level. |
I guess the questions are:
My preference is 1. yes, 2. yes. But what do others think? |
Actually since unenv currently pushes |
The behavior is definitely different. IMO changes in behavior can be classified as either a breaking change (major version) or a fix (patch version). What I think we should fo is work on the narrative for users explaining what the behavior is before and after (we will need this whether it's a breaking change or fix). But I hope that having a clear narrative will also help us classify this PR. |
I've added an alternative to this with console.log stdio prefixing in #5024. Let's please continue discussion there. |
Closing as #5024 has now been landed instead here. |
Another process follow-on that we determined could be made as an incremental improvement post-unflagging.
Instead of treating
process.stderr
as aconsole.error
instead treatingprocess.stderr
as aconsole.debug
call.In addition, this updates the STDOUT ConsoleMode to use stderr when outputting
LogLevel::DEBUG_
in workerd server.This seems to more closely align with the semantic meaning of stderr but we would need to verify the DX here.