[proposal] enhanced on-demand logging

[pq]

Proposal: Enhanced On-Demand Logging

We’ve been exploring enhanced logging in Flutter, the IntelliJ plugin and most recently in a separate package and have been encouraged by a bunch of early partner feedback. The idea hinges on treating named loggers as channels (or streams) that can be enabled and disabled on-demand via a VM service extension, allowing for configuration from clients such as IDEs or programmatically in application source.

In source, enabling named loggers looks as simple as:

logManager
  ..enableLogging('flutter.frame')
  ..enableLogging('http')
  ..enableLogging('x-factor');

and in an IDE like this:

The current package:logging can be simply enhanced to support enhanced on-demand logging in an entirely API-compatible way.

Background

flutter/flutter#21504 proposes a light-weight logging framework for Flutter and flutter/flutter#22041 offers one possible implementation and a bit more context. Finally, the logs package (unpublished) approaches the feature more generally as something that transcends Flutter and is more generally useful in Dart.

Some learnings:

• folks really like the idea of filtering on logger name (e.g., “channels”); in some cases this was preferred to log levels
• the idea of structured log data was very well received
• developers reflected that in general they were unlikely to modify core sources to enable debug logging (making the current story for enabling by debug flags in flutter foundation sources unattractive)
• there was interest in a unified story that would play well with web and Flutter logging
• the potential for IDE integration is high and valued

With these experiences in mind, we’d like to consider adding some simple facilities to the logging package. We think these ideas extend logging but don’t change it’s spirit. The benefits are ergonomics, functionality and potential for rich tool integration. With package:logging enhanced, we would not need to a new package (e.g., logs) or to land any new logging frameworks bits into Flutter foundation.

Implementation

Specifically, we’re proposing a log manager (or similar abstraction)

• that communicates w/ clients via VM service protocols and
• can be used to enable/disable loggers by name

(Secondarily, we’d like to formally expand the error message field to embrace “data” more generally.)

It’s important to note that this proposal involves NO breaking API and will leave current uses of logging facilities totally unaffected.

Use Cases

Tooling Use Case: queries (for tool integration)

IDEs (and other tools), should be able to query an app for all available loggers. Ideally, loggers could provide descriptions to help developers know what they do and why they might want to enable them.

example:

Susan is developing a flutter app and decides to try the redux package. She adds the package to her pubspec and follows the example but is confused by what’s happening. To help, she goes to the logging view and opens a "logger/channel chooser” dialog that enumerates the available loggers for her app. There are a bunch but descriptions help her identify a few to toggle that log redux lifecycle events. After playing around with her app and some sample code she’s confident she has the basic idea and disables logging.

API Use Case: programmatic enablement

Developers should be able to programmatically enabling logging channels (and not depend entirely on clients like IDEs).

example:

Sometimes Susan likes to just use vim and run her flutter app in the terminal. Turning on logging is handy for debugging so she’s happy to be able to enable it w/ a line in her app’s main.

logManager.enableLogging('redux', enable=false);

Application Use Case: networking traffic

The user would like to view (and potentially troubleshoot) the networking traffic of their app. They either:

• open the Logging view, and toggle the ‘networking’ checkbox
• open a Networking specific view

We then show http call start and stops, with http header and payload information available (ala Chrome DevTools). The implementation might work by replacing the dart:io HttpClient class (via the global override) with an implementation that logged http traffic to interested clients.

Application Use Case: (flutter) platform channels

This would be for either 1) users consuming an existing plugin (battery status; geo notifications), or 2) developers building a new native plugin. The user would go to the Logging view, toggle the ‘platform channel’ checkbox, and see all the JSON traffic going back and forth over the platform channel.

Application Use Case: package redux

User enables redux logs via a toggle in the logging view (an enhanced package:redux_logging sends redux logs to a logging stream). The user can then see the stream of state changes for their app, and, in the far-flung future, interact with them in some way to roll their app’s state backwards and forwards (a time-travelling state debugger).

Other Applications

Image Cache. Logging could provide insights into Flutter’s Image Caching system. Potential events of interest include Growing and flushing cache; it may also be interesting to call out exceptionally large images.

UI performance. Logged events might complement existing timeline and inspector views by providing insights into things like:

• slow frames
• rebuilt widgets
• repainted render objects

Battery Use. (on iOS corresponding to UIDeviceBatteryStateDidChangeNotification events.)

[natebosch]

I do think we should give strong consideration to a "fresh start" with package:logs (or package:log if we can get that author to give us the name).

The current API here suffers a few flaws that are not easy to fix:

• hierarchicalLoggingEnabled is a global variable that can get stepped on by any code - some logging behavior expects it must be set one way and will break otherwise.
• There is not a good way to group logs based on task - logger names are the only way to group logs. If the same class is involved with performing work for different tasks it can't be distinguished.
• It uses sync Streams which is not a good practice.

We had strongly considered moving away from package:logging and creating our own logging package for build but we didn't only because of time constraints.

At this point the migration cost for the ecosystem would be huge, but it's still cheaper now that it ever will be again as we pile on more use.

[pq]

Thanks for the perspective @natebosch! I'd be curious to hear more about your experience with build. In the meantime, a few more limitations come to mind wrt a reboot:

• log records currently do not carry any isolate info making multi-isolate app logging ambiguous (see: Improve logging package #22)
• hierarchical logging seems poorly understood in general (see: Unable to change logging level dynamically #44, How to set hierarchicalLoggingEnabled = true? #45)
• log filtering is currently limited (see e.g., Allow for filtered logging using onRecord() sdk#21454 which proposes onRecord.filter(Level.WARNING) or similar but the idea could be taken further)
• errors are currently the only "data" the API supports sending but we should think more broadly about logging structured data (e.g., DiagnosticNodes or user-defined JSON-encodable maps)
• in general the ergonomics of the API could be improved (consider named params over optional positional ones; allow for passing in a jsonEncodable, etc)

[natebosch]

Capturing some more thoughts for the future:

log records currently do not carry any isolate info making multi-isolate app logging ambiguous

A LogRecord can only cross the isolate boundary if both isolates have identical code. I'd very much prefer not to give the impression that sending LogRecord instances through a SendPort is a recommended approach since it won't always work. Since the app already needs to handle listening on the logs and forwarding across the isolate the log listener can handle instead sending a custom object (or serialized map) with the LogRecord and whatever isolate identifier they'd like.

errors are currently the only "data" the API supports sending but we should think more broadly about logging structured data

There is a relatively easy workaround of logging an object with a cheap .toString(). The rest of the object comes with the LogRecord. I'm open to the idea of the API having a more explicit mechanism, but I don't think it's a hard requirement.

In general I think it is best to keep this package tightly focused on what it does today - plumbing the records through to a listener, filtering by level, and allowing for lazy message evaluation for cases where building the string is expensive.

If it does make sense to be opinionated about log listeners - printing, writing to a file, managing across isolates etc, that should be handled in hopefully a separate package. The "write a log" use case is way more widespread than the "handle a log" use case - the former should see very few breaking changes while the latter can likely handle a bit more churn. It's also likely, IMO, that use cases are too specific to get a lot of value out of a shared package. package:flutter_log_handlers could make sense since a flutter app is a more targeted use case and the flutter team can likely be more opinionated.

[natebosch]

Another thing to consider - whether we can find a design that is easy to tree-shake: #20