RFC: Consolidated and Consistent Logging in Rollup

[shellscape]

RFC: Consolidated and Consistent Logging in Rollup

Consolidating the logging used within Rollup CLI and the Rollup plugin ecosystem will provide a more consistent, reliable, and enjoyable user experience. Logging used in this context is intended to inform the user while Rollup is running.

Truths

1. The CLI is currently responsible for [the majority of] logging for Rollup Core.
2. Log output (trace, debug, info, warn, error) is piped to stderr by default.
3. Program output (e.g. build result) should be piped to stdout

Deviating Scenarios

In some circumstances, log output should be piped to I/O that deviates from the usual.

Destination Based on Config

When using the config (or command line options) to direct Rollup to write the result to a specified file or location, stdout does not act the destination and therefore is not subject to pollution concerns. In this circumstance, the reasons are not clear for either using the default pipe destinations, or modifying the destination for this circumstance as a special case. While the purpose of stdout has changed, the process is not long- running.

Watching

When watching, the Rollup CLI is acting as a long-running service. As such log output is categorically different. In this circumstance, log output should behave like other common long-running tasks.

1. Non-error, non-warning log output should be piped to stdout.
2. Error, Warning, and Debug log output should be piped to stderr.

It could however, be argued that there is no valid output for stdout in this case, and that stderr should be redirected manually if the user wishes to parse the output.

Consolidated Logging

The @rollup/log project was created to address the lack of a central logger to provide consistent output to the ecosystem (core and plugins alike). This logger will ship with a default experience and rules for the Rollup experience.

Providing Loggers to Plugins

To create a consistent user experience, it's important the same logging mechanism with the same rulesets be used by all actors in the ecosystem (CLI, Core, Plugins). However, there are presently some logistical challenges in implementing that within Rollup today:

Cache

In a typical NPM/Node project, the log module would be used as per usual - a dependency that would reside in node_modules. This would allow for module caching via Node, and ease of access to instantiated loggers through a cache mechanism. Due to Rollup being rolled, and some plugins following in kind, the shared cache becomes moot.

Shared Logger

Since Rollup core does not handle log output, with that responsibility residing in the CLI, there is no obvious mechaism for passing a logger from the CLI onto plugins. Given that the rules for the Rollup ecosystem around when and to where log output is sent, coupled with various potential options that could be set via the CLI, a shared approach is preferable for ease of use and reducing developer burden. Using a shared logger also ensures that plugins will not produce faulty log output.

Possible Solutions

1. Plugins make use of @rollup/log as a dependency and instantiate their own loggers. Plugins would be responsible for checking the CLI flags to set the proper log options.
2. Logging is offloaded from the CLI to the Core. Loggers are shared with plugins at the beginning of a build.
3. Core accepts a log option which is passed to plugins at the beginning of a build, which is provided to the Core by the CLI. Users of the API will have to instantiate a log to meet their needs.
4. Core accepts a log option which is passed to plugins at the beginning of a build, which defaults to an instance using an opinionated ruleset.
5. Core provides a default log instance using an opinionated ruleset. Core accepts various log options. The CLi passes log options from CLI parameters and makes use of the log through the result of Rollup instantiation.

Preferred Solution

Logging is offloaded from the CLI to the Core. Loggers are shared with plugins at the beginning of a build.

References

1. https://www.jstorimer.com/blogs/workingwithcode/7766119-when-to-use-stderr-instead-of-stdout
2. http://www.learnlinux.org.za/courses/build/shell-scripting/ch01s04.html
3. https://www.unix.com/man-page/posix/1P/logger/
4. https://nodejs.org/api/console.html#console_console_warn_data_args

[guybedford]

My feedback on Discord was that I'm for a logging centralization, allowing logs as generic events from core. Perhaps errors as events like this even, and definitely warnings.

Handling backwards compatibility with onwarn will be important.

I also think ideally the actual std writing could be done in the CLI itself only.

Further feedback welcome.

[lukastaegert]

As for plugins, I think we should keep warn and error as they are—especially error since it is about more than logging. I would see a new log function on the plugin context to provide additional logging capabilities. I would not want a shared logging package as this would be hard to control in certain scenarios. Instead in my opinion, all logging should run through core. So that core has full control if and how things are logged.

The logs could then be handed down via the JavaScript API similar to how it is done for warnings. The actual formatting and output should be handed solely by the CLI IMO as it is the only instance that knows where we are running to keep the platform independence. That way it should be possible to write custom runners that handle logging quite differently or handle logging in a web frontend.

[shellscape]

@lukastaegert hm I think your comment might be a bit contradictory. what's throwing me for a loop is:

Instead in my opinion, all logging should run through core

followed by:

The actual formatting and output should be handed solely by the CLI IMO

Those would seem to work against each other. Could you elaborate on your ideas there?

[shellscape]

So the comments above raise some interesting additional points that need clarification. Rollup has three types of users I've been able to identify:

1. Users of the CLI
2. Users of the API (includes CLI users)
3. Users in the Browser

The solution we move forward with really has to be able to address all three. There are some pitfalls that should be addressed:

• Sending log output to the terminal only for CLI users will mean API users will have a downgraded experience, in the sense that they won't benefit from the same helpful output.
• We can't send log output to the same endpoints for CLI users and Browser users. (@rollup/log addresses this by providing a stderr override option, which for a browser build would let all log messages flow through to their respective console handler)
• We shouldn't leave any type of user without helpful logging, nor the ability to manipulate messages.

I would not want a shared logging package as this would be hard to control in certain scenarios.

This is a tough one. A shared, but project-specific, logging package provides a ton of benefit. It keeps that concern, set of specific features, and support isolated to the package. Even though Rollup bundles its dependencies and ships that bundle, it still uses a lot of outside packages. To provide robust logging for users, more than writing to stdx is needed. Things like choosing which logs to silence (easily), choosing whether or not to show timestamps, choosing how to redirect output to which stdx (or if at all), shared formatting for a consistent experience, and the tests for all of these - are all things that are better developed in a separate space outside of the rollup pipeline imho, and imported like any other utility module.

👍 to activity on this one. I think it's one of the key items to improving the user experience.

[lukastaegert]

Ok, that sounded a little confused. I will write it up properly when I have a little private time, probably not before tonight though. I think we will find a good solution here with nice encapsulation

[lukastaegert]

API users

Sending log output to the terminal only for CLI users will mean API users will have a downgraded experience, in the sense that they won't benefit from the same helpful output

I personally do not completely share this sentiment though this is certainly discussable, but let me explain. API users are usually advanced users who should have the chance to have full control as to how logs are displayed i.e. via routing them through their own logging logic. Thus they should have the opportunity to register a logging hook similar to the onwarn handler that receives any log information.

As there already is an onwarn handler, I guess a new logging hook should only apply to logs with lower levels than "warning". Only in case there is no onwarn handler I think there should be a default internal and probably simple logging in rollup core so that important warnings will not go unnoticed. On the other hand I would prefer to not show any informational or diagnostic logs by default for API users.

This could, however, be a great opportunity for either providing additional logging tools for them to plug into the hooks or special plugins that take care of logging. The latter, however, would require adding a new plugin hook here. Definitely something to muse about.

Browser users

Certainly the smallest group of users but actually very similar to the API users with the only difference that the browser build throws in situations where there would be an unhandled file access. Thus my above suggestion should work for them perfectly. We could even add a checkbox to the REPL (by far the most important browser user 😜) to have a nice way to display additional logging if we want to.

Plugin logging

In order to make this possible, plugins should never directly log to the console or stderr/out but only via hooks on the plugin context. Rollup could then create log message objects similar to the warning and error objects with additional information about which plugin logged what inside which hook. I do not think explicitly instantiating a logger by plugins should be necessary considering there is only very little overhead anyway but we can discuss this.

Performance

In order to be able to have diagnostic logs without cannibalizing performance, it should not only be possible to specify a log level but there should be different log functions for all levels so that rollup core can make sure all ignored logs can be efficiently be replaced by no-op functions. A standard this.log.info(), this.log.debug() etc. could certainly be made to fulfil this.

The CLI

The CLI should be the only one actually displaying logs by default (with the sole exception of the fallback log for warnings). This can be as elaborate as we want it to be and if you have great ideas here, go ahead and get crazy! (well, a little maybe 😜). It is also easy for the CLI to add timestamps etc. as of course all logs are synchronous.

This is the interface we recommend to all new users and I think it is the interface which is also used by most users with the exception of users with special workflow needs (like Ember CLI!) which will probably want to handle it their own way anyway.

The logging itself could of course be imported from an external source into the CLI. This would provide a way for API users to have the same logging by just importing the same library and connecting it to the logging hook.

Adding meta information to logs

Backend loggers often instantiate different loggers to have e.g. information about the class doing the logging. I am not a huge fan of this in a non-server environment as this all means additional overhead. But we can definitely talk about it. As long as ignored logs can become flat no-ops, I am happy.

Hope this kind of explains what I originally wanted to say.

I also want to say I am really glad you joined the team and are stirring things up here, there is really a lot going on at Rollup at the moment and you are a huge part of this driving us forward!

[shellscape]

Thanks for that response. Exactly what I was hoping we'd get written down. I'm going to have to let the majority of that marinate for a minute, I need to take a step back and think about this some more. I understand what the intent is, but I can't agree with that approach at the moment. I just don't think it's as beneficial to users in the end. Limiting output to the CLI is pretty niche and not very common, and IMO will make log management more difficult long term. I'll give this some time and put together a proper response.

I can say that https://github.com/rollup/log currently satisfies the requirements for a log object that you had mentioned (specifically in Performance), among other features. That would be a good reference point at the very least.

(And thanks very much for the kind words at the end!)

[lukastaegert]

Sure thing, definitely makes sense to weigh different ideas here. Might also make sense to collect different scenarios and compare how they would be handled by the different approaches to get a feeling.

It seems one point we agree upon is that plugins do not log directly but get a logger from the core. Detail to be worked out is if the plugins would need to instantiate it themselves. I would prefer less friction here but again, gathering scenarios where explicit instantiation would provide some benefits would be interesting.

[tivac]

As a plugin author I have zero interest in needing to instantiate a logger, just give me a this.log that does the right thing automatically.

I'm with @lukastaegert in terms of overall structure of how I expect rollup logging to work. Core should provide an API and hooks to get access to log details, but should not log anywhere by default. I strongly dislike APIs that log when I'm building on top of them because it takes away my ability to control the UX.

[kzc]

It would be useful to have an option to disable all emojis from this prospective logger for non-tty use and analysis. See #1201.

[kzc]

Following up from thread in #1201:

I'm not sure that asking a library or app to filter certain unicode characters is reasonable solely based on personal preference

But that's exactly what application configuration is - personal preferences - .vimrc, .prettierrc et al. I'm not asking for it to be the default, just an option.

Do note that @Rich-Harris committed the disable emoji to TTY feature in #1206. So #2393 would be reintroducing them.

There's clearly a desire among some users to optionally disable emojis. It is a commonly requested feature in projects that log. yarn is not an outlier. It'd be disappointing if Rollup lacked this ability.

[shellscape]

@kzc please address and respond to the emoji issue on #1201. This RFC doesn't cover that topic.

[kzc]

Wow, censoring a long time contributor to Rollup for an on-topic comment in an RFC. I give up. Best of luck, folks.

[shellscape]

@kcz I certainly didn't mean to offend. The comments weren't removed, only hidden as off-topic, which wasn't a derogatory action, nor censoring you. You comments are still there for reference. I do hope you reconsider and don't take it in that way, and I know that we're more than happy to discuss that topic on the other issue.

This RFC is complicated and has a lot to consider around how logging actually works, more so than the nuances of specific messages or CLI options. If we were to try and encompass every aspect of logging in a single issue, it would quickly become unproductive.

[lukastaegert]

Hi @shellscape, though I see your point in that @kzc's point is for now only tangential to the RFC at hand, I took the liberty to unhide the comments in question, no offence intended. I actually think the point is a valid one when it comes to the actual implementation as it will certainly affect quite a few users who use Rollup in advanced setups. #1201 is closed and will therefore probably not receive the necessary attention so this can be easily forgotten and the comment established the necessary link.

Please avoid hiding comments unless absolutely necessary e.g. due to inappropriate content. A short comment that you see something as off-topic as you did via https://github.com/rollup/rollup/issues/2393#issuecomment-412547763 should be enough IMO 😉Thanks!

[shellscape]

I must disagree. Those comments were tangential at best, and akin to a user introducing a new thread inside of an issue to address one's own focus of the moment. That practice is so common in fact, that Github introduced the ability to hide as off-topic explicitly to address that, and as a nicer alternative to deleting. I wouldn't go so far as to call it a thread hijack, but it's close. I also don't see any evidence that there was due diligence done to check for a regression, only a knee-jerk response to a follow up comment on a merged PR. If the goal was to reintroduce a resolved issue as unresolved, then a new issue should have been opened to address a regression.

This RFC is about the implementation of logging between the CLI, Core API, and Plugins. Not the minutia of content of individual messages, nor options to address that content. Content is the easy part. Implementation is the hard part.

[shellscape]

@lukastaegert After having given this a fair amount of thought, I think the implementation outlined below might be the best bet, and falls in line with you’re after (and may just be saying the same thing in a different way).

CLI

• Instantiates @rollup/log
• @rollup/log handles timestamps, log level, future log features
• CLI handles argument parsing, passes options onto @rollup/log
• CLI listens to API hooks designated for each log level

API

• Provides a basic log object to Plugin Context containing a named method to match each log level available (sans “silent”)
• log method will trigger API hook for designated level method used

Plugins

• this.log is available with named methods to match each log level, within plugin hook handlers.

—

This should keep the bulk of the implementation in the API light, keep the CLI light by handling only hook notifications, and offload the majority of the complexity to the existing separate log module.

There has been mention of not using a separate module to contain the log-output implementation and keeping that implementation in the code for the CLI, but I feel pretty strongly that would be a mistake. Separation of concerns is a good thing here.

[lukastaegert]

Sounds perfect to me!

[dalisoft]

Any news?

[shellscape]

@dalisoft It's still in the pipeline

[Harsh1796]

Any updates on this?

[shellscape]

@Harsh1796 please avoid replying with questions that have previously been asked. When there's an update, rest assured we'll share that.