I've had help from SO:
http://stackoverflow.com/questions/5249265/strange-behaviour-in-django-logging-django-1-3-rc/5250829#5250829

The solution is simply to explicitly call self.format(record) on my
emit() method under DatabaseHandler.

Hope this helps whoever face a similar problem.


-Edwin

On Mar 7, 8:58 am, Edwin <edwinja...@gmail.com> wrote:
> Sorry I wasn't clear enough. Here's the stack trace:
>
> Traceback:
> File "/usr/local/lib/python2.6/dist-packages/django/core/handlers/
> base.py" in get_response
>   89.                     response = middleware_method(request)
> File "/home/user/projects/django/../django/common/middleware.py" in
> process_request
>   27.             return login(request, **defaults)
> File "/usr/local/lib/python2.6/dist-packages/django/utils/
> decorators.py" in _wrapped_view
>   93.                     response = view_func(request, *args,
> **kwargs)
> File "/usr/local/lib/python2.6/dist-packages/django/views/decorators/
> cache.py" in _wrapped_view_func
>   79.         response = view_func(request, *args, **kwargs)
> File "/home/user/projects/django/../django/apps/django_extra_auth/
> views.py" in login
>   57.             auth_login(request, form.get_user())
> File "/usr/local/lib/python2.6/dist-packages/django/contrib/auth/
> __init__.py" in login
>   85.     user_logged_in.send(sender=user.__class__, request=request,
> user=user)
> File "/usr/local/lib/python2.6/dist-packages/django/dispatch/
> dispatcher.py" in send
>   172.             response = receiver(signal=self, sender=sender,
> **named)
> File "/usr/local/lib/python2.6/dist-packages/django/contrib/auth/
> models.py" in update_last_login
>   50.     user.save()
> File "/usr/local/lib/python2.6/dist-packages/django/db/models/base.py"
> in save
>   460.         self.save_base(using=using, force_insert=force_insert,
> force_update=force_update)
> File "/usr/local/lib/python2.6/dist-packages/django/db/models/base.py"
> in save_base
>   570.                 created=(not record_exists), raw=raw,
> using=using)
> File "/usr/local/lib/python2.6/dist-packages/django/dispatch/
> dispatcher.py" in send
>   172.             response = receiver(signal=self, sender=sender,
> **named)
> File "/home/user/projects/django/apps/history/audit.py" in
> post_save_handler
>   102.             logging.log_to_db(logging.INFO, msg, log_type)
> File "/home/user/projects/django/apps/history/__init__.py" in
> log_to_db
>   61.         db_logger.log(level, msg, extra=extras)
> File "/usr/lib/python2.6/logging/__init__.py" in log
>   1119.             self._log(level, msg, args, **kwargs)
> File "/usr/lib/python2.6/logging/__init__.py" in _log
>   1173.         self.handle(record)
> File "/usr/lib/python2.6/logging/__init__.py" in handle
>   1183.             self.callHandlers(record)
> File "/usr/lib/python2.6/logging/__init__.py" in callHandlers
>   1220.                     hdlr.handle(record)
> File "/usr/lib/python2.6/logging/__init__.py" in handle
>   679.                 self.emit(record)
> File "/home/user/projects/django/apps/history/handlers.py" in emit
>   11.         timestamp = datetime.strptime(record.asctime,
> settings.LOG_DATE_FORMAT)
>
> Also, I have a wrapper to call db_logger, which you can see from the
> stacktrace:
>     def log_to_db(self, level, msg, log_type, extra={}):
>         db_logger = logging.getLogger('db_logger')
>         extras = {
>             'category': log_type.category.name,
>             'sub_category': log_type.sub_category.name,
>             'type_id': log_type.type_id,
>         }
>         extras.update(extra)
>         db_logger.log(level, msg, extra=extras)
>
> My DB Handler looks like this:
>
> class DatabaseHandler(logging.Handler):
>     def emit(self, record):
>         user = getattr(record, 'user', None)
>         category = getattr(record, 'category', None)
>         sub_category = getattr(record, 'sub_category', None)
>         type_id = getattr(record, 'type_id', None)
>         timestamp = datetime.strptime(record.asctime,
> settings.LOG_DATE_FORMAT)
>         from history.models import LogRecord
>         LogRecord.objects.create(timestamp=timestamp,
> level=record.levelname,
>             category=category, sub_category=sub_category,
> type_id=type_id,
>             message=record.message, user=user)
>
> Thanks again.
>
> On Mar 5, 10:59 pm, Russell Keith-Magee <russ...@keith-magee.com>
> wrote:
>
> > On Sat, Mar 5, 2011 at 10:41 AM, Edwin <edwinja...@gmail.com> wrote:
> > > I'm getting a strange behaviour when setting up logging. Here's my
> > > logging configuration:
>
> > > LOGGING =
> > > {
> > >    'version': 1,
> > >    'disable_existing_loggers': True,
> > >    'formatters': {
> > >        'admin_configuration': {
> > >            'format': '%(asctime)s %(levelname)s %(category)s %
> > > (sub_category)s %(type_id)s %(message)s',
> > >            'datefmt': LOG_DATE_FORMAT,
> > >        },
> > >    },
> > >    'handlers': {
> > >        'admin_console': {
> > >            'level':'DEBUG',
> > >            'class':'logging.StreamHandler',
> > >            'formatter': 'admin_configuration'
> > >        },
> > >        'db': {
> > >            'level':'DEBUG',
> > >            'class':'apps.history.handlers.DatabaseHandler',
> > >            'formatter': 'admin_configuration'
> > >        },
> > >    },
> > >    'loggers': {
> > >        'db_logger': {
> > >            'handlers': [ 'admin_console', 'db' ],
> > >            'level': 'DEBUG',
> > >            'propagate': False,
> > >        },
> > >    }
> > > }
>
> > > I then created a Database log handler and the log record will be
> > > created using signals (e.g. on model save/delete) because I'm trying
> > > to keep track of model changes.  As you can see from my config, the
> > > logger has 2 handlers, 1 for DB and 1 for stdout (stream handler).
>
> > > I use the logger this way:
>
> > > logging.getLogger('db_logger').log(level, msg, extra=extras)
>
> > > where extras are extra attributes I'm passing to the logger.
>
> > > Now the weird thing is, when I change the order of 'handlers'
> > > definition under 'db_logger' to ['db', 'admin_console'], the logger
> > > raises this error:
> > > LogRecord instance has no attribute 'asctime'
>
> > > After checking the record instance, 'message' attribute is generated
> > > either, but all of my extra attributes are there.
> > > The same error happens if I remove 'admin_console' handler. The only
> > > way I can get the logger to work is that the handler must be in the
> > > original order:  'handlers': [ 'admin_console', 'db' ]
>
> > > Any idea why this is happening??
>
> > It's difficult to say. If I had to guess, I'd say there was something
> > unusual about your db logger. However, without seeing explicit stack
> > traces or sample code, that's about the best I can offer.
>
> > Yours,
> > Russ Magee %-)

-- 
You received this message because you are subscribed to the Google Groups 
"Django users" group.
To post to this group, send email to django-users@googlegroups.com.
To unsubscribe from this group, send email to 
django-users+unsubscr...@googlegroups.com.
For more options, visit this group at 
http://groups.google.com/group/django-users?hl=en.

Reply via email to