Send logs to Dart DevTools.

[CoderDake]

As part of some product excellence pursuits for Dart Devtools we would like to make sure that package:logging records are also sent to Dart Devtools.

TBD i'm going to reach out to package members to ask about the best way to test this.

[kevmoo]

Maybe opt-in, but defaulting here seems a bit too far. My $0.02

[devoncarew]

Hmm, yes, this is a core package, and I'd be concerned that developer.log() is not zero cost (esp. when there's a debugging client hooked up). I'm curious - what options have been discussed here?

[CoderDake]

@devoncarew in @bkonyi 's doc on Developer Tooling exploration, he points out that package:logging should at least have a default handler that forwards logs to developer.log. That is probably the only other option that has been looked at right now. I think this approach essentially accomplishes the same thing without having to set up another listener though.

Opt in could be a possibility for sure, but I think @bkonyi mentioned that he would prefer the dev logging by default.
Perhaps he can comment on it's importance in his own words though.

[bkonyi]

I don't think enabling this by default will result in much of a performance regression. For release mode applications, this log(...) is effectively a no-op and we can probably make further optimizations in dart:developer and package:logging to avoid unnecessary work when dart.vm.product is defined. I would be more concerned about logging performance issues related to expensive string interpolation operations that aren't tree-shaken out, even in the absence of a logging callback (I'm not sure how much of an issue this is, but I strongly suspect existing logging code isn't totally free).

Not using log(...) by default in package:logging seriously hampers the ability of developer tooling to provide structured logging support in DevTools and IDEs and puts the onus on developers to configure their logging to work correctly with first-party tooling. Most users are going to default to implementing their logging using print or stdout.writeln, completely bypassing the structured logging support already part of the SDK. This will make it more difficult for the tooling team to justify making investments in improving the Dart logging experience which, when compared to solutions like Logcat and XCodes log viewer, is extremely lacking, particularly in VSCode.

[natebosch]

I'm also worried about enabling this by default.

avoid unnecessary work when dart.vm.product is defined

What are the impacts of extra dart:developer log() calls on the web? @sigmundch

[devoncarew]

I'm very much in favor of making structured logging visible to developers and improving the support for logging in our libraries and developer tools. I think this meeds a bit more thought however than can be done in a few line PR.

One possible design would be for dart:developer to have a way to register a logging provider. When in a log view of a developer tool - like devtools - the user could toggle on the 'package:logging' stream, which would then listen for all package:logging log events. This would be zero cost when logging wasn't being used.

[sigmundch]

Thankfully for production (dart2js) this should be a noop - our patch for log is completely empty.

However, we had issues in the past with overhead from dart:developer log during development, if I recall correctly. I believe it was because of how these APIs got mapped to Chrome APis. @nshahan - you probably recall the details better than I do. Is it still a concern for us?

[nshahan]

AFAIK @elliette discovered and fixed the problem we had with our dart:developer logging implementation. I'm only not 100% sure it is fixed because I was never actually able to reproduce the problem myself and there are still sporadic unconfirmed reports of the problem still appearing. It isn't confirmed if the fix was actually live for those yet.

[bkonyi]

One possible design would be for dart:developer to have a way to register a logging provider. When in a log view of a developer tool - like devtools - the user could toggle on the 'package:logging' stream, which would then listen for all package:logging log events. This would be zero cost when logging wasn't being used.

This is already the case for log(...). If there's no listeners on the Logging stream, the event is never built and processed by the VM service.

[bkonyi]

One possible design would be for dart:developer to have a way to register a logging provider. When in a log view of a developer tool - like devtools - the user could toggle on the 'package:logging' stream, which would then listen for all package:logging log events. This would be zero cost when logging wasn't being used.

This is already the case for log(...). If there's no listeners on the Logging stream, the event is never built and processed by the VM service.

Although DDS does store a log history by default, which would cause this stream to be listened to immediately if the VM service is enabled. However, in situations where the VM service isn't enabled, there's no event created or sent.

[elliette]

AFAIK @elliette discovered and fixed the problem we had with our dart:developer logging implementation. I'm only not 100% sure it is fixed because I was never actually able to reproduce the problem myself and there are still sporadic unconfirmed reports of the problem still appearing. It isn't confirmed if the fix was actually live for those yet.

Some context on what happens for dart:developer logs on the web:

• The dart:developer implementation of log for DDC calls Chrome's console.debug API
• DWDS listens for the console.debug events and adds them to the Logging stream
• Before Fetch full developer.log messages webdev#2333, we were sending the truncated version of the log to that stream, now we send the full log
• Dart DevTools listens for events to the Logging stream and displays them

The issue that was reported saying this wasn't working was because the DWDS change wasn't in the reporter's version of Flutter: dart-lang/webdev#2400 (comment)

[CoderDake]

It sounds like we could benefit from some data on the approaches. I'll set out to test these to see what types of impacts there are.

To ensure I understand the concerns involved though. I'd like to try to summarize the approaches to be tested and how to test them. Please let me know if the following seems to touch the points in contention

App to test against

Use the CPU profiler to analyse the runtime of the following code in a flutter app (it would be run after clicking a button.)

  void _runLoggingtest() {
    final defaultTag = getCurrentTag();
    final logTestTag = UserTag('Log Test');
    logTestTag.makeCurrent();
    for (var i = 0; i < 1000000; i++) {
      log.fine('Log test i: $i');
    }
    defaultTag.makeCurrent();
  }

Cases to test

1. No changes. Just test the app as is
2. This PR's change to package:logging
3. Add log.onRecord.listen((record) => developer.log(...record)) to the test app
   • this would be a quick way to test @devoncarew's idea of a record listener that does the work for us.

States to test against

• debug
• profile
• release

[CoderDake]

Note: I'll use Stopwatch instead of the userTags (at Ben's advice)