Code

Opened 3 years ago

Closed 3 years ago

Last modified 3 years ago

#16121 closed Bug (needsinfo)

Duplicating loggin or Change formatter every time

Reported by: niwi@… Owned by: nobody
Component: Uncategorized Version: 1.3
Severity: Normal Keywords:
Cc: Triage Stage: Unreviewed
Has patch: no Needs documentation: no
Needs tests: no Patch needs improvement: no
Easy pickings: no UI/UX:

Description

I have configured a logger like this:

'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:

'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:

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:

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

Attachments (0)

Change History (2)

comment:1 Changed 3 years ago by aaugustin

  • Needs documentation unset
  • Needs tests unset
  • Patch needs improvement unset
  • Resolution set to needsinfo
  • Status changed from new to closed

I fail to see how this is related to Django:

  • logging is a module from the standard library, provided by Python.
  • gevent has no relation with Django.

So I'm pretty sure you could reproduce the same problem without Django (with a dummy wsgi app, logging.config.dictConfig, etc.).

Anyway, it's hard to diagnose your problem with the information you've provided. If you think there's a bug in Django, could you provide a simpler test case (something we can easily reproduce), and tell us which part of Django is misbehaving?

comment:2 Changed 3 years ago by anonymous

Ok. I understand that it is difficult to reproduce this bug. Keep working on this, to know where it came from.

In a few days will update this issue with more specific information if I find the problem.

Thank you very much.

Add Comment

Modify Ticket

Change Properties
<Author field>
Action
as closed
as The resolution will be set. Next status will be 'closed'
The resolution will be deleted. Next status will be 'new'
Author


E-mail address and user name can be saved in the Preferences.

 
Note: See TracTickets for help on using tickets.