Re: [racket-dev] (reposted from users) Noisy compiler at PLTSTDERR=info

2015-01-22 Thread Tony Garnock-Jones
Hi Matthew,

Thanks for those thoughts.

On 01/22/2015 09:11 AM, Matthew Flatt wrote:
> On 1 above: I've been uncertain of the best way to organize logging
> from the start, but the idea of grouping topics hierarchically (such as
> a "compilation" topic group) doesn't sound promising.

I agree. Better perhaps would be a more relational approach. There are
all sorts of cross-cutting ways one might like to filter log messages:

 - by package author ("all the messages in code I wrote")
 - by package
 - by collection
 - by module
 - by specific subroutine?
 - by level (debug, info, warning etc)
 - by phase
 - by place
 - by predicate (e.g. regexp) on log message or log datum

I don't know how to do this yet. Certainly not with the efficiency of
the current logging system!

> I guess there's
> often a mismatch between the producer's original idea of organization
> the and consumer's eventual idea.

Yes, that's a very good point.

> On 2 above: I'm not sure why compilation or phase 1 is special. As more
> and more libraries use logging, it seems like they will generate noise
> (from your perspective) at run time, too.

On reflection, I agree with you. Phase is just one of the many axes
listed above.

> In this sense, the "info" label is ambiguous. [...]
> My only idea, then, is that we're missing a level somewhere between
> "debug" and "warning".

To me it feels like there is one major divison when it comes to levels:
that between errors/warnings and informational messages. Within each
grouping, less important subdivisions exist.

If I can turn on and off the informational messages as a group, for
individual *subsystems*, I think I'm happy.

So my current "workaround" works OK for me. Adding an extra gradation
between info and debug wouldn't add much in this example.

I think I'm after finer control of selecting messages on axes *other*
than level/severity.

-- Tony

_
  Racket Developers list:
  http://lists.racket-lang.org/dev


Re: [racket-dev] (reposted from users) Noisy compiler at PLTSTDERR=info

2015-01-22 Thread Matthew Flatt
At Wed, 21 Jan 2015 11:22:38 -0500, Tony Garnock-Jones wrote:
> Over the past few months, more and more subsystems have started logging
> at info level as part of regular compilation.
> 
> I prefer having PLTSTDERR=info in order to catch log-info that happens
> at runtime, and find the compile-time log output quite distracting.
> 
> My current workaround is to set
> 
> PLTSTDERR="info warning@cm warning@compiler/cm warning@module-prefetch
> warning@setup/parallel-build warning@cm-accomplice
> warning@online-check-syntax"
> 
> but this is quite verbose, and as subsystem log messages come and go
> I'll need to keep updating it.
> 
> Could one of the following ideas be worth exploring?
> 
>  1. Have a superlogger for these (and other?) compile-time-ish loggers,
> so that I could write "info warning@compilation", excluding the
> noise in one fell swoop
> 
>  2. Have a phase number associated with logging, so I could say
> "info@0 warning@1", or similar

I have a suggestion below, but it's based on a guess of what you really
want, and it might be a bad guess.


Here's my train of thought:

On 1 above: I've been uncertain of the best way to organize logging
from the start, but the idea of grouping topics hierarchically (such as
a "compilation" topic group) doesn't sound promising. The original
implementation had a notion of hierarchy that I thought might play out
this way, but it didn't. Overall, it seems to be difficult to fit
topics into a hierarchy a priori, in much the same way that it has been
difficult or awkward to group exceptions hierarchically (and few Racket
libraries attempt to extend the exception hierarchy). I guess there's
often a mismatch between the producer's original idea of organization
the and consumer's eventual idea.

On 2 above: I'm not sure why compilation or phase 1 is special. As more
and more libraries use logging, it seems like they will generate noise
(from your perspective) at run time, too.


More generally:

The most successful step in the logging system's evolution was the move
toward "@" specifications that include specific s
of interest. In a growing sea of information, knowing which pieces you
want and specifying those pieces makes sense. Trying to exclude a
category of information is much harder, because it's hard to know all
the information that will be available to exclude.

At the same time, it makes sense to have "error" messages visible all
the time for all topics, because users should see errors that they
didn't anticipate. Similarly, it makes sense for a user to request
extra unanticipated information at the "warning" level.

In this sense, the "info" label is ambiguous. The "info" level could be
like "warning": information that a human consumer might be interested
in without anticipating it, but (unlike "warning") not a suggestion of
a problem. Or "info" could be more like "debug": details that are only
useful when you're looking closely at a specific subsystem. A potential
distinction between "info" and "debug" is that the former makes sense
to the consumer of the subsystem as opposed to the producer.

My only idea, then, is that we're missing a level somewhere between
"debug" and "warning". My guess is that you're getting too much
information from "info", because you wanted a human-volume level of
status information; sometimes "info" is used for that. Other uses of
"info" are more like "debug" --- not really human-volume --- and that's
the part you don't want to see. It happens that many of the current
"debug"-like uses of "info" are in compilation subsystems.

If I'm guessing right, then we could introduce a new level and sort out
existing uses:

 * fatal - last-ditch communication channel before termination
 * error - errors
 * warning - info for humans that alerts a potential mistake
 * info - info for humans on status and progress
 * detail - info for subsystem consumers, not necessarily human-volume
 * debug - info for subsystem implementers, not necessarily human-volume

The idea is that most of the compilation messages could move to
"detail". (Or maybe it makes sense to add the level between "info" and
"warning"; it becomes a transition and compatibility question as much
as anything.)

In retrospect, I realize that I've often struggled with choosing "info"
vs. "debug" levels precisely because I haven't been clear on which is
meant as human-volume --- or even that it makes sense to consider a
human-volume vs. machine-volume distinction. Other times, I've
struggled with "info" vs. "debug" because of a internal vs. external
distinction.


Does any of that connect to your actual situation and goals?

_
  Racket Developers list:
  http://lists.racket-lang.org/dev