[racket] 5.3's "mzc optimizer" log-debug, and log "facility" in general

From: Greg Hendershott (greghendershott at gmail.com)
Date: Wed Sep 5 17:39:58 EDT 2012

On reflection:

A per-file facility is, I think, a bit crazy. As Neil already saw.
Per-library or per-app is the right granularity.

Given that, I think the answer is almost as simple as letting each app
or library define its own named logger and its own set of log-debug
etc. macros that use that logger.

Status quo from racket/private/more-scheme.rkt is this:

  (define-syntax (log-it stx)
    (syntax-case stx ()
      [(_ id mode str-expr)
       #'(let ([l (current-logger)])
           (when (log-level? l 'mode)
             (log-message l 'mode str-expr (current-continuation-marks))))]))
  (define-syntax (define-log stx)
    (syntax-case stx ()
      [(_ id mode)
       #'(define-syntax (id stx)
           (syntax-case stx ()
             [(_ str-expr)
              #'(log-it id mode str-expr)]))]))
  (define-log log-fatal fatal)
  (define-log log-error error)
  (define-log log-warning warning)
  (define-log log-info info)
  (define-log log-debug debug)

So:

1. Rather than assume current-logger, these should create and use a
named logger.

2. There's a (define-them-all logger-name) macro that defines all of
these (the logger, log-debug, log-info, and so on).

3. Each app or lib invokes 2 in one file, and provides them for its other files.

4. We tweak XREPL to filter based on the log messages being

  "[<logger-name: >]<original-message>".

But "<logger-name: >" is "" if the logger is unnamed. So ...

5. If an app or lib doesn't do 3 -- i.e. all existing apps -- then it
gets default log-debug etc. macros which use a logger named something
specific -- such as 'all-other -- rather than the root unnamed logger.
Otherwise I don't see how 4 can reliably exclude their messages.

Is that about the shape of it?

On Wed, Sep 5, 2012 at 2:31 PM, Greg Hendershott
<greghendershott at gmail.com> wrote:
> Before I saw your email, I sketched out a hypothetical successor to
> the current log system: ogl <https://github.com/greghendershott/ogl>
>
> I would definitely be willing to help suggest how to change XREPL's
> ,log command to do some optional regexp filtering.
>
> As I mention in the README, I guess I'm confused/skeptical how this
> will really work upstream -- what is the "best practice" to tell
> people, and will they actually do it?  For example it seems like with
> the status quo system, if people use the handy log-debug etc. wrappers
> to log-message, they're likely to do the wrong thing. Instead they
> either need to:
>
> A. Make/use a logger with a name (so that gets prepended in the log
> message).  But in this case they can't use log-debug etc. which assume
> current-logger. Instead they have to restrict themselves to
> log-message.
>
> OR
>
> B. Prepend some facility name to all their calls. In this case they
> _can_ use log-debug etc. But will they always?  If it's error-prone,
> it's likely log messages will leak.
>
> So ... I don't know. I'd love to see an approach where the
> easy/obvious/naive way people will tend to do it, is the preferred
> way.
>
> On Wed, Sep 5, 2012 at 7:02 AM, Eli Barzilay <eli at barzilay.org> wrote:
>> On Thursday, Robby Findler wrote:
>>>
>>> > But stipulating I could filter in whatever fashion ...
>>> >
>>> > 2. Putting this in every source file doesn't seem practical? I'm
>>> > talking about doing interactive development, using XREPL's ,log
>>> > command. Open a file, evaluate it, make some changes, maybe use
>>> > ,log to tweak the log output level, evaluate, move on to another
>>> > file. That sort of work-flow.
>>>
>>> IIUC, this is something you'd do instead of using ,log.  You can
>>> require some helper library with the function in it, or probably Eli
>>> has some way to add more commands or something like that.  Or maybe
>>> even a patch to ,log that'd let you specify a regexp in the case
>>> that string munging was the best option?
>>
>> Regardless of the potential extensions that will come out of this
>> discussion, it's pretty obvious that something like the above would be
>> very helpful.  Greg: looks like you know where the source of the xrepl
>> ,log command is, so if you see a nice way to extend it, then I'll be
>> happy to go over it and do the change.
>>
>> Maybe something like this? --
>>
>>   instead of
>>
>>     ,log <level>
>>
>>   you get
>>
>>     ,log <logspec> ...₁
>>
>>   where the <logspec>s are "and"-combined, and each one can be:
>>
>>     <level>        same as now, for a symbol, integer, or boolean
>>     "prefix"       show all messages that start with "prefix"
>>     #rx"text"      show all messages that match the regexp
>>
>>   And possibly even another one:
>>
>>     (lambda ...) or (λ ...)
>>                    an explicit user-defined filtering function
>>
>>   This is a little ugly, since it would have to be a syntactic
>>   function form, so another alternative is that if the <level> is not
>>   one of the known symbols (or a boolean, number, string, or regexp),
>>   then it's considered an expression.  Another alternative is to make
>>   the log level always be an expression, so you'll need to change your
>>   use of ",log something" to ",log 'something".  (Incompatible, but
>>   this is an interactive tool anyway, and it sounds like you're the
>>   most interested user of it...)
>>
>> As for an extension, while it sounds fine to have the optimization
>> information appear in a "more hidden" way, I think that overall this
>> will continue to be a problem -- like you said, in cases where you add
>> your own logging information.  Personally, I don't think that there's
>> any problem with doing the filtering "mostly" at the string prefix
>> level, since this is a facility that is ultimately producing
>> information in textual form...  In addition it works nicely for unix
>> log files, and there's probably a bunch of tools that could work with
>> it too -- in contrast to dealing with Windows log events that are much
>> harder (IME) to deal with (unless you serialize them into strings
>> first...).
>>
>> And BTW, tying some default log format to the module sounds good in
>> theory, but I think that it can often be a bad idea since modules are
>> smaller components than what you're usually interested in, which is
>> "my library".  An alternative that could be useful is to just have
>> some log form that prefixes the output with its source location (eg,
>> as the usual "/dir/file.rkt:1:2:" prefix), which you can then use with
>> a prefix filtering.
>>
>> --
>>           ((lambda (x) (x x)) (lambda (x) (x x)))          Eli Barzilay:
>>                     http://barzilay.org/                   Maze is Life!


Posted on the users mailing list.