[Haskell-cafe] attempt creating alternative logging lib which is actually much slower (?)

Marc Weber marco-oweber at gmx.de
Thu Feb 12 08:47:01 EST 2009


> > without removing all all setLevel calls to subloggers?
> > Is this desirable?
> 
> I don't understand the problem.  If you told hslogger that you didn't
> want to hear about stuff about "A", why do you not like that it is
> following your instructions?

Because taht >>don't want to hear abuot "A"<< could have been set
without my knowledge. When trouble shooting a problem it could be handy
to just get all messages. But when such a use case arrives I can still
patch hslogger.


mlog (attempt to create a minimal alternative)
====

I've tried writing another minimal logging system.
The idea was driven by adding the possibility to add a handler logging
everything not matter what levels are set to different loggers or
handlers.

The design is simple: keep a list of log handlers and a list of filters.
you can add a filter telling that a log message of "A.B" should not be
logged. The actual handler function then looks like this

  log shouldbeLogged logmessage loggername prio = ....

So you can still ignore shouldbeLogged easily.
However I couldn't even come close to the speed of hslogger even when
caching the list of handlers which are supposed to log the message.

[some code snippets see end of mail]

without any attached handlers:

  hslogger*[1] : 4ms
  mlog[2]: 12ms

with one default stderr logger (./test 2> /dev/null)

  hslogger*[1] : 109ms 
  mlog[2]:   150ms 

[1]: my modified version of hslogger (git://mawercer.de/hslogger)
[2]: (git://mawercer.de/mlog)

I've tried doing some investigation figuring out why my lib is that much
slower but I failed. I noticed that -O2 had an impact on how often the
list of generated test cases is run. But that has been all. I don't even
use existential types!

So I'll shut up and keep using hslogger. Thanks to you John Goerzen
for your support.

I've learned that I'm very bad at troubleshooting performance.
I really thought I could make mlog faster than hslogger*.
Using profiling (-P) didn't reveal the source wasting CPU cycles to me.

Sincerly
Marc Weber

[ some code snippets of mlog]


the global logger data looks like this:

  data GlobalLoggerData = GlobalLoggerData {

    handlers :: M.Map Int LogHandler 
      -- assign a key so that this logger can be removed easily again 

    ,filters :: M.Map Int GlobalFilter -- allow to add global filters 

    -- cache information about which logger accepts what logging data
    -- String = Priority : loggername
    , cached :: M.Map String (Bool, [ LogMessageAction ])

  }

  {-# NOINLINE globalLoggerData #-}
  globalLoggerData :: MVar GlobalLoggerData
  globalLoggerData = unsafePerformIO $ newMVar $ GlobalLoggerData M.empty M.empty M.empty


  -- add default handler: 
  addHandler $ LogHandler {
    accept = \ln p -> True -- which logging events does this log handler accept? 
    ,logAction = \ln p msg doLog -> hPutStrLn stderr msg 
    ,close = return ()
  }


More information about the Haskell-Cafe mailing list