Bugs item #1516995, was opened at 2006-07-04 14:34
Message generated for change (Comment added) made by vsajip
You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=105470&aid=1516995&group_id=5470

Please note that this message will contain a full copy of the comment thread,
including the initial issue submission, for this request,
not just the latest update.
Category: Python Library
Group: Python 2.5
Status: Open
Resolution: None
Priority: 5
Private: No
Submitted By: Collin Winter (collinwinter)
Assigned to: Vinay Sajip (vsajip)
Summary: test_logging fails with reference count-checking enabled

Initial Comment:
When running from the following, test_logging fails:
./python Lib/test/regrtest.py -R :: test_logging.

Here's the traceback:

test test_logging crashed -- <type
'exceptions.KeyError'>: <logging.StreamHandler instance
at 0xb7aaebcc>
Traceback (most recent call last):
  File "Lib/test/regrtest.py", line 554, in runtest_inner
    dash_R(the_module, test, indirect_test, huntrleaks)
  File "Lib/test/regrtest.py", line 673, in dash_R
    run_the_test()
  File "Lib/test/regrtest.py", line 660, in run_the_test
    indirect_test()
  File
"/home/collin/src/python/Lib/test/test_support.py",
line 299, in inner
    return func(*args, **kwds)
  File
"/home/collin/src/python/Lib/test/test_logging.py",
line 677, in test_main
    test_main_inner()
  File
"/home/collin/src/python/Lib/test/test_logging.py",
line 640, in test_main_inner
    globals()['test%d' % t]()
  File
"/home/collin/src/python/Lib/test/test_logging.py",
line 347, in test2
    sh.close()
  File
"/home/collin/src/python/Lib/logging/__init__.py", line
687, in close
    del _handlers[self]
KeyError: <logging.StreamHandler instance at 0xb7aaebcc>




This problem does not occur when run without reference
count-checking.

System info:
Python SVN r47224
Linux 2.6.13
x86

----------------------------------------------------------------------

>Comment By: Vinay Sajip (vsajip)
Date: 2007-03-11 00:58

Message:
Logged In: YES 
user_id=308438
Originator: NO

Thanks for the info. test2() is a little sensitive because it makes
assumptions about the state of handlers attached to the root logger.
test4() and test5() do some slightly dodgy manipulation of the internal
handler list maintained by the module. I played around with the assumption
that test5() is the culprit (as it's the last test run), and found that
adding the lines

        hdlr = logging.getLogger().handlers[0]
        logging.getLogger().handlers.remove(hdlr)

in test5(), just after the line

        os.remove(fn)

causes the error not to occur, and the test passes successfully. Please
try this on your system and re-run the tests, and if you can confirm that
this change works for you, I can check it in. (I propose to only check it
into trunk, and not into release25-maint or other branches - what do you
think?)

----------------------------------------------------------------------

Comment By: Collin Winter (collinwinter)
Date: 2007-03-10 20:36

Message:
Logged In: YES 
user_id=1344176
Originator: YES

Vinay: I've been able to gather a little more information.

The problem occurs during the second run-through of the test suite; that
is, it runs once, then "-R ::" kicks in and starts to run the test again,
which is when the exception occurs. From what I can tell from poking around
test2(), something is removing the "sh" handler from logging._handlers
prematurely (its id() matches that displayed in the KeyError traceback).

More poking around: "-R ::" doesn't really enter into it. Modifying
test_main_inner() to run test2() more than once (in isolation or after
other tests) will trigger this, too. On the second run, sh.close() raises a
KeyError.

----------------------------------------------------------------------

Comment By: Vinay Sajip (vsajip)
Date: 2007-03-10 17:25

Message:
Logged In: YES 
user_id=308438
Originator: NO

Hi Collin,

I'm sorry to be so slow on this. For various reasons, I don't have a debug
build of Python 2.5 :-(, without which the -R option is not available to
me. Also, of course, it's not a bug in logging itself, more in the test
case.

If you have time, I would appreciate some help on this: I would
temporarily modify test_logging to print out the StreamHandlers created
either explicity in test_logging.py or via the calls to fileConfig(), to
see which StreamHandler is not being released. TIA...

----------------------------------------------------------------------

Comment By: Collin Winter (collinwinter)
Date: 2007-03-09 20:42

Message:
Logged In: YES 
user_id=1344176
Originator: YES

Still present as of 54248. Vinay, do you have any insights on this?

----------------------------------------------------------------------

Comment By: Collin Winter (collinwinter)
Date: 2006-09-01 04:03

Message:
Logged In: YES 
user_id=1344176

This issue is still present as of r51654.

----------------------------------------------------------------------

You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=105470&aid=1516995&group_id=5470
_______________________________________________
Python-bugs-list mailing list 
Unsubscribe: 
http://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

Reply via email to