>> If the user doesn't need those values and can provide cheap
    >> substitutes, perhaps their computation can be avoided.  I did that
    >> recently by inlining only the parts of logging.LogRecord.__init__ in
    >> a subclass and avoided calling logging.LogRecord.__init__ altogether.
    >> It generated lots of instance variables we never use and just slowed
    >> things down.

    Vinay> Well, that approach is fine if you need maximal performance. If
    Vinay> those values set in LogRecord.__init__ can be computed more
    Vinay> cheaply than they are at present, please give an idea as to where
    Vinay> speedups can be applied, or even supply a patch ;-) 

Note the prefix "If the user doesn't need those values".  I don't need much
of the stuff that LogRecord.__init__ computes for each LogRecord
instantiation, so None would be a fine, cheap substitute for me. <wink>

In general we do a lot of logging at work because stuff happens so fast
(we're writing automated trading applications) that you can't tell what's
happening in real-time.  Your only opportunity for analysis is post-mortem.
Consequently, we tend to log a bunch of stuff that is rarely needed, but is
critical to have around when it is needed.  In fact, the folks who write C++
apps here tossed out log4cpp altogether and wrote their own logging package
because log4cpp was too slow.  To give you an idea how much logging we do, I
wrote a CompressedRotatingFileHandler class because our apps log so much
data that we need to compress them to avoid filling up disks.

    Vinay> If you don't need many of the values set by LogRecord.__init__,
    Vinay> then your approach is fine (until someone decides they want
    Vinay> something which is documented and tries to access it via a
    Vinay> specific format string - which could be done, in the general
    Vinay> case, via configuration changes).

This is used within a single app, so I'm not too worried about that.  All we
ever call the log routines with is a caller-formatted string.  There is no
substitution required of the logging package.  Most of the stuff you provide
we simply don't need.  Like I said, we log a lot of stuff.  When our
application's main CPU user is the logging package it's time to look at the
logging package with an eye to cutting out what we don't need.

    Vinay> The use case I'm supporting with this is one where some/most/all
    Vinay> of the default attributes are wanted, 

I would argue the stuff I've thrown out isn't used by most apps.  Here's
what I inlined:

        self.name = name
        self.msg = msg
        self.args = args
        self.levelname = logging.getLevelName(level)
        self.levelno = level
        self.pathname = pathname
        self.filename = os.path.basename(pathname)
        self.module = os.path.splitext(self.filename)[0]
        self.exc_info = exc_info
        self.lineno = lineno

self.created is either set to time.time() (when we run live) or our internal
tick stream clock time (when we do historical runs).

Here's what I avoided setting:

    self.thread - most apps, ours included, are not multithreaded, so
        knowing the current thread id is superfluous

    try/except on self.filename/self.module - not sure why this is necessary
        or what the except clause is catching - I've never seen an exception

    self.relativeCreated - we only use absolute time

    self.process - we never to record the process id as each process
        generates its own log files.

Plus I of course avoided the overhead of the __init__ function call itself.

    Vinay> With the proposed scheme the extra value is passed to LogRecord
    Vinay> constuction code so it could be used by your custom LogRecord
    Vinay> initialiser with the same benefit as in the general case (I
    Vinay> think).

Sure, I'd be happy to use extra dict if it suppressed the superfluous
calculations, e.g.:

    if 'relativeCreated' in extra:
        self.relativeCreated = extra['relativeCreated']
    else:
        self.relativeCreated = (self.created - _startTime) * 1000

Maybe adding all those tests will just slow down the common case though.
Perhaps extra should be used to override *all* logRecord attributes:

    if extra:
        self.__dict__.update(extra)
    else:
        ... do the usual initialization ...

In that case it would be the caller's responsibility to make sure that extra
contains everything they need.  To insure that, a static LogRecord method
could be used to return a default extras dict:

    extras = LogRecord.get_default_extra()

    while True:
        ... compute ...
        ... maybe override some values in extras ...
        logging.info(..., extra=extras)
        ... compute some more ...

Skip
_______________________________________________
Python-Dev mailing list
Python-Dev@python.org
http://mail.python.org/mailman/listinfo/python-dev
Unsubscribe: 
http://mail.python.org/mailman/options/python-dev/archive%40mail-archive.com

Reply via email to