Login | Register For Free | Help
Search for: (Advanced)

Mailing List Archive: Python: Bugs

[issue6435] logging: cache the traceback text on formatter, instead of record

 

 

Python bugs RSS feed   Index | Next | Previous | View Threaded


report at bugs

Jul 7, 2009, 7:18 PM

Post #1 of 11 (259 views)
Permalink
[issue6435] logging: cache the traceback text on formatter, instead of record

New submission from Sridhar Ratnakumar <sridharr [at] activestate>:

In Formatter.format():

# Cache the traceback text to avoid converting it multiple
times
# (it's constant anyway)
if not record.exc_text:
record.exc_text = self.formatException(record.exc_info)

The result must ideally be cache on the formatter object (self) itself
rather than the record object. Because, record object is reused in
multiple handlers .. thus multiple formatters. If the first formatter,
caches the traceback text, then subsequent formatters will use the same
even though of them is apparently a custom Formatter with overridden
`formatException`.

----------
components: Library (Lib)
messages: 90247
nosy: srid, vsajip
severity: normal
status: open
title: logging: cache the traceback text on formatter, instead of record
versions: Python 2.6, Python 2.7, Python 3.1, Python 3.2

_______________________________________
Python tracker <report [at] bugs>
<http://bugs.python.org/issue6435>
_______________________________________
_______________________________________________
Python-bugs-list mailing list
Unsubscribe: http://mail.python.org/mailman/options/python-bugs-list/list-python-bugs%40lists.gossamer-threads.com


report at bugs

Jul 7, 2009, 7:18 PM

Post #2 of 11 (244 views)
Permalink
[issue6435] logging: cache the traceback text on formatter, instead of record [In reply to]

Changes by Sridhar Ratnakumar <sridharr [at] activestate>:


----------
type: -> behavior

_______________________________________
Python tracker <report [at] bugs>
<http://bugs.python.org/issue6435>
_______________________________________
_______________________________________________
Python-bugs-list mailing list
Unsubscribe: http://mail.python.org/mailman/options/python-bugs-list/list-python-bugs%40lists.gossamer-threads.com


report at bugs

Jul 7, 2009, 7:25 PM

Post #3 of 11 (244 views)
Permalink
[issue6435] logging: cache the traceback text on formatter, instead of record [In reply to]

Sridhar Ratnakumar <sridharr [at] activestate> added the comment:

For example, see: http://paste.pocoo.org/show/127167/

----------

_______________________________________
Python tracker <report [at] bugs>
<http://bugs.python.org/issue6435>
_______________________________________
_______________________________________________
Python-bugs-list mailing list
Unsubscribe: http://mail.python.org/mailman/options/python-bugs-list/list-python-bugs%40lists.gossamer-threads.com


report at bugs

Jul 8, 2009, 4:31 PM

Post #4 of 11 (239 views)
Permalink
[issue6435] logging: cache the traceback text on formatter, instead of record [In reply to]

Sridhar Ratnakumar <sridharr [at] activestate> added the comment:

A real-life recipe where this bug showed up:

http://code.activestate.com/recipes/576836/

----------

_______________________________________
Python tracker <report [at] bugs>
<http://bugs.python.org/issue6435>
_______________________________________
_______________________________________________
Python-bugs-list mailing list
Unsubscribe: http://mail.python.org/mailman/options/python-bugs-list/list-python-bugs%40lists.gossamer-threads.com


report at bugs

Jul 8, 2009, 11:59 PM

Post #5 of 11 (239 views)
Permalink
[issue6435] logging: cache the traceback text on formatter, instead of record [In reply to]

Vinay Sajip <vinay_sajip [at] yahoo> added the comment:

I fail to follow your logic, in the following respects:

1. The exception text cannot be cached in the formatter because a
formatter will format lots and lots of records. Formatters live for a
long time, records do not.
2. The exception text needs to be stored in the record, because in some
instances (e.g. pickling and sending over a socket) this information
will not be available at the other end in any other way.
3. The way it works now, if you have multiple formatters attached to
multiple handlers (e.g. with ISO time for log files, with no ISO time
for console output), then the traceback is only converted to text once.
4. There's nothing stopping you from overriding Formatter.format, is
there? the base version uses the cache, you can override format in your
custom formatter and ignore the cache altogether if you like.

Are you sure you've thought this through? ;-)

----------
assignee: -> vsajip
resolution: -> invalid
status: open -> closed

_______________________________________
Python tracker <report [at] bugs>
<http://bugs.python.org/issue6435>
_______________________________________
_______________________________________________
Python-bugs-list mailing list
Unsubscribe: http://mail.python.org/mailman/options/python-bugs-list/list-python-bugs%40lists.gossamer-threads.com


report at bugs

Jul 9, 2009, 12:19 AM

Post #6 of 11 (241 views)
Permalink
[issue6435] logging: cache the traceback text on formatter, instead of record [In reply to]

Sridhar Ratnakumar <sridharr [at] activestate> added the comment:

On Wed, 08 Jul 2009 23:59:17 -0700, Vinay Sajip <report [at] bugs>
wrote:

> 1. The exception text cannot be cached in the formatter because a
> formatter will format lots and lots of records. Formatters live for a
> long time, records do not.

Ah, yes.

> Are you sure you've thought this through?

Not thoroughly .. as I missed the point 1. on formatter processing
multiple records.

----------

_______________________________________
Python tracker <report [at] bugs>
<http://bugs.python.org/issue6435>
_______________________________________
_______________________________________________
Python-bugs-list mailing list
Unsubscribe: http://mail.python.org/mailman/options/python-bugs-list/list-python-bugs%40lists.gossamer-threads.com


report at bugs

Jul 9, 2009, 12:33 AM

Post #7 of 11 (239 views)
Permalink
[issue6435] logging: cache the traceback text on formatter, instead of record [In reply to]

Vinay Sajip <vinay_sajip [at] yahoo> added the comment:

> Not thoroughly .. as I missed the point 1. on formatter processing
> multiple records.

But what do you say to points 2, 3 and 4? Of course they may not apply
to your use case, but are they not valid points?

----------

_______________________________________
Python tracker <report [at] bugs>
<http://bugs.python.org/issue6435>
_______________________________________
_______________________________________________
Python-bugs-list mailing list
Unsubscribe: http://mail.python.org/mailman/options/python-bugs-list/list-python-bugs%40lists.gossamer-threads.com


report at bugs

Jul 9, 2009, 1:06 AM

Post #8 of 11 (239 views)
Permalink
[issue6435] logging: cache the traceback text on formatter, instead of record [In reply to]

Sridhar Ratnakumar <sridharr [at] activestate> added the comment:

> 2. The exception text needs to be stored in the record, because in some
> instances (e.g. pickling and sending over a socket) this information
> will not be available at the other end in any other way.

Caching in the record object is thus the way to go. But the cache needs to
be invalidated when `exc_info` is changed .. as in set to None when it was
a traceback object. I'd change the following:

if record.exc_text:
if s[-1:] != "\n":

to:

if record.exc_info and record.exc_text:
if s[-1:] != "\n":

(or, move the body of this IF to the preceding IF)

> 3. The way it works now, if you have multiple formatters attached to
> multiple handlers (e.g. with ISO time for log files, with no ISO time
> for console output), then the traceback is only converted to text once.

Yes, that is the benefit of caching I see.

> 4. There's nothing stopping you from overriding Formatter.format, is
> there? the base version uses the cache, you can override format in your
> custom formatter and ignore the cache altogether if you like.

I can, but I'd rather not duplicate that code. From the recipe I linked
above:

def format(self, record):
# attach 'error:' prefix to error/critical messages
s = logging.Formatter.format(self, record)
if record.levelno >= logging.ERROR:
return 'error: {0}'.format(s)
else:
return s

Here, I simply call the base class's `format` method.

And do you know of a better way to suppress traceback output (in the
custom handler during `log.exception`) than the hack used in the recipe?

elif record.levelno >= logging.ERROR:
if record.exc_info and self.verbosity_level < 1:
# supress full traceback with verbosity_level <= 0
with new_record_exc_info(record, None):
self.__emit(record, sys.stderr)
else:
self.__emit(record, sys.stderr)

.. http://code.activestate.com/recipes/576836/

----------

_______________________________________
Python tracker <report [at] bugs>
<http://bugs.python.org/issue6435>
_______________________________________
_______________________________________________
Python-bugs-list mailing list
Unsubscribe: http://mail.python.org/mailman/options/python-bugs-list/list-python-bugs%40lists.gossamer-threads.com


report at bugs

Jul 9, 2009, 3:02 AM

Post #9 of 11 (239 views)
Permalink
[issue6435] logging: cache the traceback text on formatter, instead of record [In reply to]

Vinay Sajip <vinay_sajip [at] yahoo> added the comment:

> But the cache needs to be invalidated when `exc_info` is changed -
> as in set to None when it was a traceback object.

When does the exc_info change for a record? AFAIK it's set when you
create a LogRecord, and that's it.

To be honest, I'm not sure why you need that specific recipe. Notice
the comment made by a user against the recipe. But if you are set on
doing it like this, then suppose I configure as follows:

Create a StreamHandler(sys.stderr) and a StreamHandler(sys.stdout).
Create a Formatter and attach it to the output handler.
Create a Formatter with the format string used above but with
an "error:" prefix, and attach it to the error handler.
Add a Filter to each handler. This can be a single Filter class which
either passes everything above a threshold or everything below a
threshold. This will only have a few lines of code. Attach two such
instances, suitably configured, to the appropriate handlers.
Attach both handlers to the root logger (or some other logger).

How will this differ in its effect from your recipe?

----------

_______________________________________
Python tracker <report [at] bugs>
<http://bugs.python.org/issue6435>
_______________________________________
_______________________________________________
Python-bugs-list mailing list
Unsubscribe: http://mail.python.org/mailman/options/python-bugs-list/list-python-bugs%40lists.gossamer-threads.com


report at bugs

Jul 9, 2009, 1:02 PM

Post #10 of 11 (239 views)
Permalink
[issue6435] logging: cache the traceback text on formatter, instead of record [In reply to]

Sridhar Ratnakumar <sridharr [at] activestate> added the comment:

> Vinay Sajip <vinay_sajip [at] yahoo> added the comment:
>
>> But the cache needs to be invalidated when `exc_info` is changed -
>> as in set to None when it was a traceback object.
>
> When does the exc_info change for a record? AFAIK it's set when you
> create a LogRecord, and that's it.

Ok.

> To be honest, I'm not sure why you need that specific recipe. Notice
> the comment made by a user against the recipe.

I've responded as well .. that will explain why I need this specific
recipe.

> But if you are set on
> doing it like this, then suppose I configure as follows:
>
> Create a StreamHandler(sys.stderr) and a StreamHandler(sys.stdout).
> Create a Formatter and attach it to the output handler.
> Create a Formatter with the format string used above but with
> an "error:" prefix, and attach it to the error handler.
> Add a Filter to each handler. This can be a single Filter class which
> either passes everything above a threshold or everything below a
> threshold. This will only have a few lines of code. Attach two such
> instances, suitably configured, to the appropriate handlers.
> Attach both handlers to the root logger (or some other logger).
>
> How will this differ in its effect from your recipe?

Actually, I did not know about 'Filter' until now. I will give it a try
sometime.

----------

_______________________________________
Python tracker <report [at] bugs>
<http://bugs.python.org/issue6435>
_______________________________________
_______________________________________________
Python-bugs-list mailing list
Unsubscribe: http://mail.python.org/mailman/options/python-bugs-list/list-python-bugs%40lists.gossamer-threads.com


report at bugs

Jul 9, 2009, 4:54 PM

Post #11 of 11 (239 views)
Permalink
[issue6435] logging: cache the traceback text on formatter, instead of record [In reply to]

Vinay Sajip <vinay_sajip [at] yahoo> added the comment:

[.snip example of how to achieve same effect as recipe in a simpler way]
>> How will this differ in its effect from your recipe?

> Actually, I did not know about 'Filter' until now. I will give it a
> try sometime.

Wouldn't it improve your recipe further to use more effectively
functionality which is already present in the logging package, instead
of re-inventing the wheel? Filter has been part of the logging package
design from the beginning, and is reasonably well documented.

If my suggestion has the same effect as your recipe, it has the further
benefit of users being able to specify thresholds more flexibly. For
example, in your response to a comment on your recipe, you acknowledge
that perhaps the destination you initially chose for DEBUG message might
need to be reconsidered. This means that it's probably better to provide
mechanism, and leave policy more to the user. With moderately careful
design of the Filter class, more flexibility could be provided with no
real penalty in code size or complexity.

----------

_______________________________________
Python tracker <report [at] bugs>
<http://bugs.python.org/issue6435>
_______________________________________
_______________________________________________
Python-bugs-list mailing list
Unsubscribe: http://mail.python.org/mailman/options/python-bugs-list/list-python-bugs%40lists.gossamer-threads.com

Python bugs RSS feed   Index | Next | Previous | View Threaded
 
 


Interested in having your list archived? Contact Gossamer Threads
 
  Web Applications & Managed Hosting Powered by Gossamer Threads Inc.