classification
Title: Logical mistake of importer method in logging.config.BaseConfigurator
Type: Stage: resolved
Components: Library (Lib) Versions: Python 2.7
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: vinay.sajip Nosy List: Alexandr, Bluebird75, ncoghlan, python-dev, r.david.murray, vinay.sajip
Priority: normal Keywords: patch

Created on 2011-08-09 17:25 by Alexandr, last changed 2013-03-25 23:38 by python-dev. This issue is now closed.

Files
File name Uploaded Description Edit
config_importer_patch.diff Alexandr, 2011-08-09 17:25 Bug patch diff variant review
test_logging.py Alexandr, 2011-08-10 17:36 inheritance example
Messages (13)
msg141834 - (view) Author: Александр (Alexandr) Date: 2011-08-09 17:25
At line 377 __import__ function assing to class variable importer.

__import__ get module name as first argument, but when we use self.importer at line 391 (http://hg.python.org/cpython/file/10f20ad2fbb6/Lib/logging/config.py#l391) we give class instance(self) as the first argument. Not module name

As result raised ImportError with message: "__import__() argument 1 must be string, not DictConfigurator" or "__import__() argument 1 must be string, not BaseConfigurator"
msg141851 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2011-08-10 08:27
It works as expected for me:

vinay@eta-jaunty:~/projects/python/2.7$ python2.7
Python 2.7.2+ (2.7:7d5a37ce42d5, Aug 10 2011, 09:20:30) 
[GCC 4.3.3] on linux2
Type "help", "copyright", "credits" or "license" for more information.
>>> import logging.config
[62163 refs]
>>> c = logging.config.BaseConfigurator({})
[62173 refs]
>>> c.importer('pickle')
<module 'pickle' from '/home/vinay/projects/python/2.7/Lib/pickle.py'>
[65944 refs]
>>> c.importer
<built-in function __import__>
[65944 refs]
>>> c.__class__.importer
<built-in function __import__>
[65944 refs]
>>> c.__class__.importer('marshal')
<module 'marshal' (built-in)>
[65944 refs]
>>> 

Can you provide an example script which demonstrates failure? I'll mark this as invalid and pending, and close soon if no further information is forthcoming.
msg141857 - (view) Author: Александр (Alexandr) Date: 2011-08-10 11:19
Install rpdb2 or winpdb for you python. And install django to you python path.
Create empty djnago-project:
django-admin createproject bbbtest 

Add line LOGGING_CONFIG = 'logging.config.dictConfig' to setting.py for use python logging.config for logging.

Execute rpdb2 ./manage.py help

And you get traceback:


Traceback (most recent call last):
  File "/home/alex/.pythonbrew/pythons/Python-2.7.1/lib/python2.7/site-packages/rpdb2.py", line 14499, in <module>
    ret = rpdb2.main()
  File "/home/alex/.pythonbrew/pythons/Python-2.7.1/lib/python2.7/site-packages/rpdb2.py", line 14470, in main
    StartServer(_rpdb2_args, fchdir, _rpdb2_pwd, fAllowUnencrypted, fAllowRemote, secret)
  File "/home/alex/.pythonbrew/pythons/Python-2.7.1/lib/python2.7/site-packages/rpdb2.py", line 14220, in StartServer
    imp.load_source('__main__', _path)    
  File "/tmp/bbbtest/manage.py", line 11, in <module>
    execute_manager(settings)
  File "/home/alex/.pythonbrew/pythons/Python-2.7.1/lib/python2.7/site-packages/django/core/management/__init__.py", line 438, in execute_manager
    utility.execute()
  File "/home/alex/.pythonbrew/pythons/Python-2.7.1/lib/python2.7/site-packages/django/core/management/__init__.py", line 368, in execute
    sys.stderr.write(self.main_help_text() + '\n')
  File "/home/alex/.pythonbrew/pythons/Python-2.7.1/lib/python2.7/site-packages/django/core/management/__init__.py", line 239, in main_help_text
    commands = get_commands().keys()
  File "/home/alex/.pythonbrew/pythons/Python-2.7.1/lib/python2.7/site-packages/django/core/management/__init__.py", line 101, in get_commands
    apps = settings.INSTALLED_APPS
  File "/home/alex/.pythonbrew/pythons/Python-2.7.1/lib/python2.7/site-packages/django/utils/functional.py", line 276, in __getattr__
    self._setup()
  File "/home/alex/.pythonbrew/pythons/Python-2.7.1/lib/python2.7/site-packages/django/conf/__init__.py", line 42, in _setup
    self._wrapped = Settings(settings_module)
  File "/home/alex/.pythonbrew/pythons/Python-2.7.1/lib/python2.7/site-packages/django/conf/__init__.py", line 139, in __init__
    logging_config_func(self.LOGGING)
  File "/home/alex/.pythonbrew/pythons/Python-2.7.1/lib/python2.7/logging/config.py", line 782, in dictConfig
    dictConfigClass(config).configure()
  File "/home/alex/.pythonbrew/pythons/Python-2.7.1/lib/python2.7/logging/config.py", line 581, in configure
    '%r: %s' % (name, e))
ValueError: Unable to configure handler 'mail_admins': __import__() argument 1 must be string, not DictConfigurator
msg141866 - (view) Author: R. David Murray (r.david.murray) * (Python committer) Date: 2011-08-10 14:49
Vinay: you want to mark importer as a static method anyway, otherwise it won't work with pypy.  I don't know why this would show up on CPython, though.
msg141870 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2011-08-10 15:33
@Александр: It still works for me without winpdb/rpdb2, so you should probably report this there. Can you confirm that it works as expected when you do "python manage.py help"?

vinay@eta-natty:/tmp$ virtualenv -p python2.7 bbbenv
Running virtualenv with interpreter /usr/bin/python2.7
New python executable in bbbenv/bin/python2.7
Also creating executable in bbbenv/bin/python
Installing setuptools............................done.
Installing pip...............done.
vinay@eta-natty:/tmp$ source bbbenv/bin/activate
(bbbenv)vinay@eta-natty:/tmp$ easy_install django
Searching for django
Reading http://pypi.python.org/simple/django/
Reading http://www.djangoproject.com/
Best match: Django 1.3
Downloading http://media.djangoproject.com/releases/1.3/Django-1.3.tar.gz
Processing Django-1.3.tar.gz

[output snipped]

Installed /tmp/bbbenv/lib/python2.7/site-packages/Django-1.3-py2.7.egg
Processing dependencies for django
Finished processing dependencies for django
(bbbenv)vinay@eta-natty:/tmp$ django-admin.py startproject bbbtest
(bbbenv)vinay@eta-natty:/tmp$ cd bbbtest
(bbbenv)vinay@eta-natty:/tmp/bbbtest$ python manage.py help
Usage: manage.py subcommand [options] [args]

[output snipped]

(bbbenv)vinay@eta-natty:/tmp/bbbtest$ grep LOGGING_CONFIG settings.py
LOGGING_CONFIG = 'logging.config.dictConfig'

@David: Marking as a static method simply ensures that the attribute is returned as a function, which is already happening:

>>> class C:
...     @staticmethod
...     def func(x): print x
...     def meth(self, x): print x
... 
>>> C.func, C.meth, C().func, C().meth
(<function func at 0xb783ddf4>, <unbound method C.meth>, <function func at 0xb783ddf4>, <bound method C.meth of <__main__.C instance at 0xb75cafcc>>)
>>> import logging.config
>>> DC = logging.config.DictConfigurator
>>> DC.importer, DC.configure, DC({}).importer, DC({}).configure
(<built-in function __import__>, <unbound method DictConfigurator.configure>, <built-in function __import__>, <bound method DictConfigurator.configure of <logging.config.DictConfigurator object at 0xb75b520c>>)

I have no objection to changing things to support PyPy, but what's the idiom? I don't believe importer = staticmethod(__import__) will work here, as it just creates a staticmethod object (which isn't callable).
msg141873 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2011-08-10 16:09
BTW I just tested on PyPy. The following program:

import logging.config
import sys

d = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'console': {
            'level': 'DEBUG',
            'class': 'logging.StreamHandler',
            'stream': 'ext://sys.stdout',
        }
    },
    'root': {
        'level': 'DEBUG',
    }
}

logging.config.dictConfig(d)
logging.debug('%s', sys.version)

prints:

vinay@eta-natty:~/projects/scratch$ python dctest.py
DEBUG:root:2.7.1+ (r271:86832, Apr 11 2011, 18:05:24) 
[GCC 4.5.2]
vinay@eta-natty:~/projects/scratch$ ~/pypy-c-jit-43780-b590cf6de419-linux/bin/pypy dctest.py 
DEBUG:root:2.7.1 (b590cf6de419, Apr 30 2011, 02:00:38)
[PyPy 1.5.0-alpha0 with GCC 4.4.3]
msg141879 - (view) Author: Александр (Alexandr) Date: 2011-08-10 17:36
As I understand, you created importer as a class attribute, so we can opportunity set import function to importer when inheritance new class from BaseConfigurator(# We might want to use a different one, e.g. importlib)? As example importer = import_module # from importlib.

>It still works for me without winpdb/rpdb2, so you should probably report this there. Can you confirm that it works as expected when you do "python manage.py help"?

You true. rpdb2 create wrapper for __import__ and self.importer not work such __builtin__ __import__

ps. Sorry for bad english, it is't primary language.
msg141881 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2011-08-10 19:19
Okay, the problem occurs because builtin functions and Python functions are handled differently. This is how you need to set a Python importer:

vinay@eta-natty:~$ python
Python 2.7.1+ (r271:86832, Apr 11 2011, 18:05:24) 
[GCC 4.5.2] on linux2
Type "help", "copyright", "credits" or "license" for more information.
>>> import logging.config
>>> BC = logging.config.BaseConfigurator
>>> from importlib import import_module
>>> class CC(BC):
...     importer = staticmethod(import_module)
... 
>>> CC.importer
<function import_module at 0xb746db54>
>>> CC.importer('pickle')
<module 'pickle' from '/usr/lib/python2.7/pickle.pyc'>
>>> CC({}).importer('pickle')
<module 'pickle' from '/usr/lib/python2.7/pickle.pyc'>

I will update the documentation to indicate this, but I don't think a change to logging.config is needed.
msg141904 - (view) Author: Roundup Robot (python-dev) Date: 2011-08-11 12:47
New changeset 0fbd44e3f342 by Vinay Sajip in branch '2.7':
Issue #12718: Add documentation on using custom importers.
http://hg.python.org/cpython/rev/0fbd44e3f342

New changeset 1e96a4406565 by Vinay Sajip in branch '3.2':
Issue #12718: Add documentation on using custom importers.
http://hg.python.org/cpython/rev/1e96a4406565

New changeset 76964d70c81c by Vinay Sajip in branch 'default':
Closes #12718: Merge documentation fix from 3.2.
http://hg.python.org/cpython/rev/76964d70c81c
msg185201 - (view) Author: Philippe Fremy (Bluebird75) Date: 2013-03-25 13:12
This issue is closed, but the problems remain that the current version of winpdb is incompatible with django + python 2.7 .

I don't really understsand why the issue is closed without any change to python logging library itself.

To sum-up the issue:
1. django uses some standard interface of logging
2. winpdb replaces the builtin __import__ with a custom python function
3. logging stores the __import__ value in a class attribute
4. python calls class attributes differently whether they are a builtin function (direct function call) or python function (which becomes a bound method, receiving self as first argument).

The problem comes from point 4, but the root of the problem is that logging assumes that it is always storing a builtin function.

The documentation fix does not fix the problem. 

How could winpdb apply this fix ? Should it check that the argument passed to its import replacement are not by mistake a DictConfigurator instance (bound method of logging class) ? That sounds like an ugly workaround for a problem lying in python logging module.

The correct fix is that logging should not assume importer to be a builtin function and add some flexibility around this.
msg185202 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2013-03-25 14:31
As suggested in the documentation, you could assign the importer as an attribute of the configurator *instance*, in which case it shouldn't be treated as a bound method. What happens if you use the suggestion in the documentation change referred to here?
msg185208 - (view) Author: R. David Murray (r.david.murray) * (Python committer) Date: 2013-03-25 16:30
See also issue 11470.  I admit that this topic confuses me; I'm not sure where the bug is, but it seems to me from reading that issue that assuming the behavior of a builtin is not correct.
msg185246 - (view) Author: Roundup Robot (python-dev) Date: 2013-03-25 23:38
New changeset e35eafc872cd by Vinay Sajip in branch '2.7':
Issue #12718: Set importer on instance if Python function, to avoid bad interaction with winpdb.
http://hg.python.org/cpython/rev/e35eafc872cd
History
Date User Action Args
2013-03-25 23:38:43python-devsetmessages: + msg185246
2013-03-25 16:30:22r.david.murraysetmessages: + msg185208
2013-03-25 14:31:33vinay.sajipsetmessages: + msg185202
2013-03-25 13:12:17Bluebird75setnosy: + Bluebird75
messages: + msg185201
2011-08-11 13:37:59r.david.murraysetnosy: + ncoghlan
2011-08-11 12:47:08python-devsetstatus: pending -> closed

nosy: + python-dev
messages: + msg141904

resolution: not a bug -> fixed
stage: resolved
2011-08-10 19:19:38vinay.sajipsetstatus: open -> pending

messages: + msg141881
2011-08-10 17:36:20Alexandrsetfiles: + test_logging.py
status: pending -> open
messages: + msg141879
2011-08-10 16:09:12vinay.sajipsetstatus: open -> pending
2011-08-10 16:09:02vinay.sajipsetstatus: pending -> open

messages: + msg141873
2011-08-10 15:33:05vinay.sajipsetstatus: open -> pending

messages: + msg141870
2011-08-10 14:49:44r.david.murraysetnosy: + r.david.murray
messages: + msg141866
2011-08-10 11:19:43Alexandrsetstatus: pending -> open

messages: + msg141857
2011-08-10 08:27:32vinay.sajipsetstatus: open -> pending
resolution: not a bug
messages: + msg141851
2011-08-09 17:42:50benjamin.petersonsetassignee: vinay.sajip

nosy: + vinay.sajip
2011-08-09 17:25:41Alexandrcreate