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

From: Matthew Flatt (mflatt at cs.utah.edu)
Date: Fri Dec 12 18:27:21 EST 2014

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


Posted on the users mailing list.