Django logging project and app namespace

Question

I've an issue with Django logging. By the way answers to this question will help me to clarify how Django namespaces work.

Here is the structure of my project:

MyProject:
    -App1:
         ....
         views.py
    -App2:
         ....
    urls.py
    settings.py

I like to log all messages in one file. Then I've setup in settings.py the following logger:

LOGGING = {
    'version': 1,
    'disable_existing_loggers': True,
    'formatters': {
            'verbose': {
                    #'format': '%(levelname)-8s %(remote_addr)-15s %(path_info)s %(asctime)s %(name)-20s %(funcName)-15s %(message)s'
                    'format': '%(levelname)-8s %(asctime)s %(name)-20s %(funcName)-15s %(message)s'
                    },
            },
    'handlers': {
            'normal': {
            'level': 'DEBUG',
            'class': 'logging.FileHandler',
            'formatter': 'verbose',
            'filename': os.path.join('C:/dev/Instantaneus/Instantaneus/html/static', 'log', 'normal.log')
        },
            'console': {
            'level': 'DEBUG',
            'class': 'logging.StreamHandler',
            'formatter': 'verbose',
            },
        },
    'loggers': {
        'MyProject': {
                'handlers': ['normal','console'],
                'level': 'DEBUG',
                #'filters': ['request'],
                'propagate': True,
                },
            }
       }

In urls.py:

from MyProject.App1.views import EvenementDetailView,
....
url(r'App1/(?P<pk>\d+)/$', login_required(EvenementDetailView.as_view(model=Evenement)), name='evenement_details'),

and in App1/views.py:

from django.views.generic import DetailView
import logging
logger = logging.getLogger(__name__)

....

class EvenementDetailView(DetailView):
    print __name__
    model=Evenement
    ....
    logger.debug('blabla')

In the browser, when I call http://localhost/App1/3, the following appears in the console:

DEBUG    2012-01-18 14:59:04,503 Myproject.evenements.views EvenementDetailView blabla
MyProject.evenements.views
evenements.views

Then my question is why the print __name__ code is executed twice and most important why outputs are not the same ?

I suppose that the DEBUG log appear only one time because evenement.views can't propagate to MyProject because in this case root is evenements

Any ideas ?

Solution, not with in depth explanation but it works:

In my urls.py, I had a line url(r'App1/(?P<pk>\d+)/activate/$', 'app1.views.activate') where 'activate' is a function in App1/views.py. I've change 'App1.views.activate' in 'MyProject.app1.views.activate' and it works fine. I've only one line in the console for print __name__. I think I've only one line because of the 'disable_existing_loggers': True, but what I can't explain is that this solution made my views.py only parse one time instead of two times before. To be sure of that I've added a print "blabla" at the beginning of the file. In first case he's printed two times and only onces in second case.

Answer 1

Fair warning: I'm not sure this is correct, and I'm basing some of this on stuff I remember reading a long time ago, but can't find in google now.

What you're seeing is a side-effect of how the python import mechanism works. When a module is imported, it's put into sys.modules, however, when it's possible to import the module under two different dotted paths (in this case, with or without MyProject) it can be imported twice, once under each __name__.

The underlying fix is to make sure MyProject it not on sys.path - the directory containing MyProject should be, but not MyProject itself. You can verify that this is done by starting a manage.py shell and making sure import evenements fails. There are some Django internals in manage.py that could make this difficult - but the last time I ran into this was back around 1.0 or 1.1, so it may well have been fixed.

There's an in-depth discussion here:

http://blog.dscpl.com.au/2010/03/improved-wsgi-script-for-use-with.html

It's a long article, search for "two different names".