Odd behavior with imp.reload and logging

[Andrew Berg]

When using a logger in a module and then using imp.reload to reload the
module, logger messages are repeated in direct proportion to the number
of times the modules was loaded. That is, on the first import, the
message is written once, but on the second run, each message is written
twice, three times on the third run, and so on.

With this code:

> import logging
> 
> test_logger = logging.getLogger(__name__)
> console_handler = logging.StreamHandler()
> console_formatter = logging.Formatter('{asctime} - {module} - {funcName} - line {lineno} - {levelname} - {message}', style='{')
> console_handler.setFormatter(console_formatter)
> test_logger.addHandler(console_handler)
> test_logger.setLevel(logging.DEBUG)
> 
> test_logger.info('Test info')

I get this in the interpreter:

> Python 3.2.2 (default, Sep  4 2011, 09:07:29) [MSC v.1500 64 bit (AMD64)] on win32
> Type "help", "copyright", "credits" or "license" for more information.
>>>> import os, imp
>>>> import test2
> 2011-09-21 20:51:02,421 - test2 - <module> - line 11 - INFO - Test info
>>>> imp.reload(test2)
> 2011-09-21 20:51:10,665 - test2 - <module> - line 11 - INFO - Test info
> 2011-09-21 20:51:10,665 - test2 - <module> - line 11 - INFO - Test info
> <module 'test2' from 'test2.py'>


What causes this, and how can I fix it (or at least work around it)? Due
to the nature of the program, it's much more convenient to reload a
module than to restart the entire program (especially when testing).

-- 
CPython 3.2.2 | Windows NT 6.1.7601.17640 | Thunderbird 6.0.2
PGP/GPG Public Key ID: 0xF88E034060A78FCB