[racket] avoiding unnecessary work when using `log-debug` et al

Thanks. I understood that Racket starts default receivers, but I didn't
understand that when you create a new logger with `define-logger` that it
also passes messages to those receivers. But I now see that's the
significance of  `define-logger` creating a logger that's a "child of
(current-logger)".

On Fri, Dec 12, 2014 at 3:27 PM, Matthew Flatt <mflatt at cs.utah.edu> wrote:
>
> By default, Racket starts receivers at 'error to direct logged errors
> to stderr and syslog. Running your program with
>
>   racket -W none -L none ....
>
> avoids the call to `expensive`.
>
> At Fri, 12 Dec 2014 14:27:24 -0800, Matthew Butterick wrote:
> > I see that you're right about `log-debug`, but here's the example that
> led
> > me to make an incorrect generalization. It seems that the (expensive)
> > function in `log-test-error` always runs, even if the level is 'none or
> > 'fatal. I don't understand why.
> >
> > #lang racket
> >
> > (define-logger test)
> >
> > (define current-level (make-parameter #f))
> >
> > (define (activate-test-logger)
> >   (define receiver (make-log-receiver test-logger (current-level)))
> >   (void (thread
> >          (λ ()
> >            (let loop ()
> >              (match (sync receiver)
> >                [(vector event-level event-message event-value name)
> >                 (eprintf (format "[~a] ~a\n" event-level event-message))
> >                 (loop)]))))))
> >
> > (define (expensive from)
> >   (displayln (format "expensive op requested from log-test-~a at level
> ~v"
> > from (current-level)))
> >   (apply + (range 5000000)))
> >
> > (parameterize ([current-level 'none])
> >   (activate-test-logger)
> >   (log-test-fatal (format "fatal at level ~v" (current-level)))
> >   (log-test-error "error at level ~v = ~a" (current-level) (expensive
> > "error"))
> >   (log-test-debug "debug at level ~v = ~a" (current-level) (expensive
> > "debug")))
> >
> > On Fri, Dec 12, 2014 at 1:49 PM, Vincent St-Amour <stamourv at ccs.neu.edu>
> > wrote:
> > >
> > > I may be missing something, but `log-debug` and friends already do
> that.
> > >
> > >     stamourv at westmount:2014-12-12 16:45:plt$ racket
> > >     Welcome to Racket v6.1.1.6.
> > >     -> (log-debug (begin (displayln "hello!") "log"))
> > >     ->
> > >     stamourv at westmount:2014-12-12 16:45:plt$ racket -W debug
> > >     Welcome to Racket v6.1.1.6.
> > >     GC: 0:min @ 1,356K(+307K)[+160K]; free 932K(-5,028K) 4ms @ 12
> > >     GC: 0:min @ 1,813K(+3,946K)[+232K]; free 755K(-2,051K) 4ms @ 20
> > >     GC: 0:min @ 4,040K(+4,087K)[+232K]; free 1,448K(-1,448K) 4ms @ 28
> > >     GC: 0:min @ 5,015K(+3,112K)[+240K]; free 1,425K(-6,817K) 4ms @ 40
> > >     GC: 0:min @ 7,459K(+6,060K)[+272K]; free 2,162K(-3,458K) 0ms @ 56
> > >     GC: 0:min @ 9,356K(+6,211K)[+280K]; free 1,628K(-2,924K) 4ms @ 72
> > >     GC: 0:min @ 13,230K(+4,353K)[+296K]; free 2,558K(-16,142K) 12ms @
> 96
> > >     GC: 0:min @ 17,224K(+13,943K)[+392K]; free 3,900K(-6,492K) 12ms @
> 136
> > >     GC: 0:min @ 21,878K(+12,457K)[+400K]; free 4,741K(-6,037K) 12ms @
> 172
> > >     GC: 0:min @ 27,016K(+9,255K)[+988K]; free 6,168K(-8,760K) 16ms @
> 232
> > >     GC: 0:min @ 32,548K(+6,315K)[+1,276K]; free 7,665K(-26,641K) 36ms
> @ 312
> > >     -> (log-debug (begin (displayln "hello!") "log"))
> > >     hello!
> > >     log
> > >     ->
> > >
> > > `log-message`, however, does not.
> > >
> > > The problem may be that, when you switch to the lower logging level,
> > > your old listener for the higher level is still around to receive the
> > > messages.
> > >
> > > Vincent
> > >
> > >
> > >
> > > At Fri, 12 Dec 2014 13:32:41 -0800,
> > > Matthew Butterick wrote:
> > > >
> > > > Is there a reason not to redefine `log-debug` et al as macros that
> > > evaluate their arguments lazily?
> > > >
> > > > Sort of like this;
> > > >
> > > > (if ((current-logging-level) . is-equal-or-above? . 'debug)
> > > >   (log-debug arg ...)
> > > >   (void))
> > > >
> > > > Because I find that my use of these functions often looks like this:
> > > >
> > > > (log-debug "Value = ~a" (expensive-operation-for-logging-purposes))
> > > >
> > > > The problem is that when I change to a lower logging level, the
> > > (expensive-operation) is still evaluated.
> > > >
> > > > I asked a similar question about hash-ref! not long ago. The answer
> was
> > > that you can get lazy evaluation by wrapping the default argument in a
> > > lambda, like so:
> > > >
> > > > (hash-ref! hashtable key (λ () (expression-that-produces-value)))
> > > >
> > > > But it seems there's no equivalent idiom for `log-debug` et al.
> > > > ____________________
> > > >   Racket Users list:
> > > >   http://lists.racket-lang.org/users
> > >
> > ____________________
> >   Racket Users list:
> >   http://lists.racket-lang.org/users
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.racket-lang.org/users/archive/attachments/20141212/b6d4e04d/attachment.html>