id	summary	reporter	owner	description	type	status	component	version	severity	resolution	keywords	cc	stage	has_patch	needs_docs	needs_tests	needs_better_patch	easy	ui_ux
16121	Duplicating loggin or Change formatter every time	niwi@…	nobody	"I have configured a logger like this:


{{{
#!python
'niwi':{
    'handlers': ['console'],
    'level': 'DEBUG',
    'propagate': False, 
},
'niwibe_console': {
    'handlers': ['niwibe_console_handler'],
    'level': 'DEBUG',
    'propagate': False, 
}
}}}


And the configuration of handlers and formatters like this:

{{{
#!python
'formatters': {
    'verbose': {
        'format': '%(asctime)s:%(levelname)s:%(module)s:%(process)d:%(message)s'
    },
    'null': {
        'format': '%(message)s',
    }
},
'handlers': {
    'null': {
        'level':'DEBUG',
        'class':'django.utils.log.NullHandler',
    },
    'console':{
        'level':'DEBUG',
        #'class':'logging.StreamHandler',
        'class':'niwi_logging.handlers.GreenStreamHandler',
        'formatter': 'verbose'
    },
    'niwibe_console_handler': {
        'level': 'DEBUG',
        'class': 'niwi_logging.handlers.GreenStreamHandler',
        #'class': 'logging.StreamHandler',
    },
    'mail_admins': {
        'level': 'ERROR',
        'class': 'django.utils.log.AdminEmailHandler',
    },
},
}}}

I have this class as the view:


{{{
#!python
from django.views.generic import View
from django.http import HttpResponse
import logging

local_loggers = {}

class TestView(View):
    def get(self, request, *args, **kwargs):
        logger_key = ""niwibe_console""
        logger_val = ""test""

        if logger_key in local_loggers:
            logger_obj = local_loggers[logger_key]
        else:
            local_loggers[logger_key] = logging.getLogger(logger_key)
            logger_obj = local_loggers[logger_key]


        # debug
        print logger_obj.handlers
        print logger_obj.parent
            
        logger_obj.info(logger_key)
        return HttpResponse('ok', mimetype=""text/plain"")
}}}

The handler used is:

{{{
#!python
from gevent.queue import Queue
from gevent import sleep, spawn
from logging import StreamHandler

class GreenStreamHandler(StreamHandler):
    """""" Gevent-based experimental async StreamHandler implementation.""""""

    _log_queue = Queue()
    def __init__(self, *args, **kwargs):
        #super(GreenStreamHandler, self).__init__(*args, **kwargs)
        StreamHandler.__init__(self, *args, **kwargs)
        self.grl = spawn(self.__save_loop)

    def __save_loop(self):
        while True:
            record = self._log_queue.get()
            #super(GreenStreamHandler, self).emit(record)
            StreamHandler.emit(self, record)
        
    def emit(self, record):
        self._log_queue.put_nowait(record)
}}}



I get a strange result. Sometimes I get one formatter sometimes not:


{{{
[<niwi_logging.handlers.GreenStreamHandler object at 0x2f28210>]
<logging.RootLogger object at 0x2d39fd0>
2011-05-29 14:45:18,627:INFO:views:20051:niwibe_console

[<niwi_logging.handlers.GreenStreamHandler object at 0x2f28210>]
<logging.RootLogger object at 0x2d39fd0>
niwibe_console

[<niwi_logging.handlers.GreenStreamHandler object at 0x2f28210>]
<logging.RootLogger object at 0x2d39fd0>
niwibe_console

[<niwi_logging.handlers.GreenStreamHandler object at 0x2f28210>]
<logging.RootLogger object at 0x2d39fd0>
2011-05-29 14:45:21,383:INFO:views:20051:niwibe_console
}}}


Is not the first time it happens! Similar things happened to me without using Gevent, in a standard environment with mod_wsgi and apache ...

Environment:
python 2.7
django 1.3
linux
"	Bug	closed	Uncategorized	1.3	Normal	needsinfo			Unreviewed	0	0	0	0	0	0