[racket] avoiding unnecessary work when using `log-debug` et al
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