Vinay:

Yes, the bulk of the time was spent in getEffectiveLevel().  Since that
method is only called by isEnabledFor(), it made sense to cache
isEnabledFor().  But, that probably reflects the characteristics of my use
of logging.  I never call getEffectiveLevel() otherwise, so caching
isEnabledFor() minimized the total cost of logging.  I think you could
sensibly argue for caching getEffectiveLevel().

I had somewhat shallow logger hierarchies (3-4 deep).  The real problem was
that this was being called in a kernel of my code ... so even that
additional cost was noteworthy.

I think it's smart to focus on Python 3.3. As it happens, my colleagues did
some explicit caching of logging information that made pyutilib.logging
redundant.  When you don't think you need this as a reference
implementation, I'll delete it.

--Bill

On Wed, Mar 2, 2011 at 2:25 AM, Vinay Sajip <report@bugs.python.org> wrote:

>
> Vinay Sajip <vinay_sajip@yahoo.co.uk> added the comment:
>
> Bill,
>
> Thanks for the suggestion and the patch. It's a good idea, though I wonder
> whether you found that the bulk of the time spent in isEnabledFor() was
> actually spent in getEffectiveLevel()? That's the one which loops through a
> logger's ancestors looking for a level which is actually set, so intuitively
> it would take a while - especially for deeper levels in the logging
> hierarchy. If so (which I suspect to be the case, but it would be good to
> have you confirm it), a better solution may be to cache the effective level.
>
> Roughly how deep are/were your logger hierarchies in the situation where
> you experienced performance problems?
>
> I'm happy to look at caching effective level for Python 3.3: The 2.X
> branches are now closed for additions other than bugs and security issues.
>
> ----------
> assignee:  -> vinay.sajip
>
> _______________________________________
> Python tracker <report@bugs.python.org>
> <http://bugs.python.org/issue11369>
> _______________________________________
>