serve command is printing logger names

[jakemac53]

It looks like this is because it is using the build_daemon which does log the logger names. We could fix it in the build daemon or here, but generally we have been doing the processing here.

[jakemac53]

cc @grouma

[grouma]

Can you give an example?

[jakemac53]

webdev serve:

[INFO] Serving `web` on http://localhost:8080
[INFO] Build: Running build completed, took 3.1s
[INFO] Build: Caching finalized dependency graph completed, took 211ms
[INFO] Build: Succeeded after 3.3s with 2 outputs (11 actions)

pbr serve:

[INFO] Generating build script completed, took 375ms
[INFO] Setting up file watchers completed, took 13ms
[INFO] Waiting for all file watchers to be ready completed, took 116ms
[INFO] Reading cached asset graph completed, took 333ms
[INFO] Checking for updates since last build completed, took 831ms
[INFO] Running build completed, took 331ms
[INFO] Caching finalized dependency graph completed, took 195ms
[INFO] Succeeded after 534ms with 0 outputs (0 actions)
Serving `web` on http://localhost:8080
Serving `test` on http://localhost:8081

The difference is the part right after [INFO], where the logger name appears. It might be useful to discuss in person but basically today build_runner has a list of known logger names that it hides.

[natebosch]

Do we do that labeling on the build_runner side and send it as a single string, or do we get separate fields for the logger names? If it's the former then we'd need to do some kind of check for stuff up to the : which sounds brittle to me.

[natebosch]

Also see dart-lang/build#2194 with some discussion about options to move away from the hardcoded list - I'd hope to avoid duplicating that list here.

[grouma]

It's sent as a single string so we'll need to do some brittle string checking. Alternatively we can expose these logger names from build_runner and build_runner_core although I don't like that option much.

[natebosch]

We'd have a versioning problem - you can have a newer build_runner that adds new logger names and they wouldn't be caught.

Maybe we can get back the logger name suppressing on the build side of things? Does webdev make it act like it's always in verbose mode or something?

[grouma]

Verbosity is configurable. I believe it is false by default. This could be a bug?

[natebosch]

It's because we're using the Logger packages built in toString() behavior here: https://github.com/dart-lang/build/blob/83ea53f8dcfef04e17784698656c376f7e3e58c4/build_runner/lib/src/daemon/daemon_builder.dart#L156

This does not use our custom log record formatting which is defined here:
https://github.com/dart-lang/build/blob/83ea53f8dcfef04e17784698656c376f7e3e58c4/build_runner/lib/src/logging/std_io_logging.dart#L29

[grouma]

Thanks for the code pointers. It definitely would be easier to handle on the daemon side. On a related note I think running two instances of webdev, one with verbosity set to true, will cause option skew. That's kind of a crummy experience.

[natebosch]

Ouch - yeah anything that doesn't impact the build output should ideally not cause skew. We should dig in on that.

We might consider setting it up so that the daemon sends everything over the socket and we do the verbosity level handling in webdev

[jakemac53]

Ya I ran into this today when working on #298 and had the same thought, we should consider sending all logs all the time.

The downside is that we will be doing a fair bit of log processing potentially which is completely throwaway work (in the standard workflows, without -v).