Custom logger is not being triggered when DEBUG=False

Question

I have the following piece of code in settings.py:

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'filters': {
        'require_debug_true': { '()': 'django.utils.log.RequireDebugTrue', },
    },
    'handlers': {
        'console': {
            'filters': ['require_debug_true'],
            'class': 'logging.StreamHandler',
        },
        'kodular': {
            'level': 'WARNING',
            'class': 'account.reporter.KodularExceptionHandler',
        },
    },
    'loggers': {
        'django': {
            'handlers': ['console', 'kodular'],
            'level': os.getenv('DJANGO_LOG_LEVEL', 'DEBUG'),
        },
    },
}

The KodularExceptionHandler class looks like this:

from copy import copy
import json
import logging
import requests

from django.conf import settings
from django.utils.log import AdminEmailHandler
from django.views.debug import ExceptionReporter

class KodularExceptionHandler(AdminEmailHandler):
    def emit(self, record, *args, **kwargs):
        print("Triggered")
        try:
            request = record.request
            subject = record.getMessage()
        except Exception:
            return

        if record.exc_info:
            exc_info = record.exc_info
        else:
            exc_info = (None, record.getMessage(), None)

        reporter = ExceptionReporter(request, is_email=True, *exc_info)
        message = "%s\n\n%s" % (self.format(copy(record)), reporter.get_traceback_text())

        text = "**Error Level**: *%s* | **Status Code**: `%s`\n\n\n" % (record.levelname, record.status_code)

        url = 'https://api.github.com/repos/'+settings.GITHUB_ORG+'/'+settings.GITHUB_REPO+'/issues'
        session = requests.Session()
        session.auth = (settings.GITHUB_USERNAME, settings.GITHUB_PASSWORD)
        issue = {'title': subject,
                'body': text+message.replace('*', '\*').replace('_', '\_'),
                'labels': ["error"]}
        r = session.post(url, json.dumps(issue))
        if r.status_code != 201:
            return
        github_issue_url = json.loads(r.content)['html_url']



        if record.levelname == "WARNING":
            return

        attachments =  [{
            'title': subject,
            'color': 'danger',
            'actions': [{
                'type': 'button',
                'text': 'Github Issue',
                'url': github_issue_url,
                'style': 'primary',
            }],
            'fields': [{
                "title": "Level",
                "value": record.levelname,
                "short": True
            },{
                "title": "Method",
                "value": request.method if request else 'No Request',
                "short": True
            },{
                "title": "Path",
                "value": request.path if request else 'No Request',
                "short": True
            },{
                "title": "User",
                "value": ( (request.user.username + ' (' + str(request.user.pk) + ')'
                        if request.user.is_authenticated else 'Anonymous' )
                        if request else 'No Request' ),
                "short": True
            },{
                "title": "Status Code",
                "value": record.status_code,
                "short": True
            },{
                "title": "UA",
                "value": ( request.META['HTTP_USER_AGENT']
                        if request and request.META else 'No Request' ),
                "short": False
            },{
                "title": 'GET Params',
                "value": json.dumps(request.GET) if request else 'No Request',
                "short": False
            },{
                "title": "POST Data",
                "value": json.dumps(request.POST) if request else 'No Request',
                "short": False
            }]
        }]

        data = { 'payload': json.dumps({'attachments': attachments}) }
        webhook_url = settings.SLACK_HOOK
        r = requests.post(webhook_url, data=data)

When I set DEBUG = True in settings, everything works properly: console handles the error (and prints "Reached"), Github issue gets created and Slack notification is sent.

However, if I set DEBUG = False, things go wrong. As it's supposed to be, console outputs less information; but neither Github issue gets created or Slack notification is sent.

I think there is an issue somewhere on the logger handler. It looks like KodularExceptionHandler is not being triggered, as console doesn't print "Reached", whereas when debug is enabled it does.

Any idea what can be causing the custom error reporting class of not being triggered when debug is set to false?

score 1 · Answer 1 · answered Apr 18 '19 at 15:00

1

This is happening because this is the default behaviour (as defined in the config) of the AdminEmailHandler, which is the parent class of your KodularExceptionHandler class. Since the AdminEmailHandler class has the django.utils.log.RequireDebugFalse filter enabled when the django app is loading (https://github.com/django/django/blob/stable/2.2.x/django/utils/log.py#L49), this filter extends to any classes inheriting from the handler.

You can either use the setting 'disable_existing_loggers': True, or not inherit from AdminEmailHandler at all. If you look at the code of AdminEmailHandler (https://github.com/django/django/blob/stable/2.2.x/django/utils/log.py#L79), you will note that you have overridden most of its code (except the __init__). Maybe you can inherit from logging.Handler instead.

answered Apr 18 '19 at 15:00

sourya

165
1
1
9

I know, but the problem is that it's working in the other way. It works only when DEBUG=True – Diego Barreiro Apr 18 '19 at 15:31
@DiegoBarreiro you're contradicting yourself. In your question you say it works when DEBUG=False: "When I set DEBUG = False in settings, everything works properly" – dirkgroten Apr 18 '19 at 16:45
@dirkgroten Yeah, sorry, I realized now... I messed the question, I have edited it now. I was able to fix the issue, there was an issue with my custom views; I'll write now the answer. – Diego Barreiro Apr 18 '19 at 21:31

score 0 · Accepted Answer · answered Apr 18 '19 at 21:34

There was a little issue on my urls.py file. I am using custom error pages handlers:

from account import views

handler404 = views.error404
handler500 = views.error500

However, the file views.py looks like this:

from django.shortcuts import render

from account.admin import requires_login

def error404(request, *args, **kwargs):
    return render(request, 'error/404.html')

def error500(request, *args, **kwargs):
    return render(request, 'error/500.html')

I fixed everything by changing it to

from django.shortcuts import render

from account.admin import requires_login

def error404(request, *args, **kwargs):
    return render(request, 'error/404.html', status=404)

def error500(request, *args, **kwargs):
    return render(request, 'error/500.html', status=500)

Custom logger is not being triggered when DEBUG=False

2 Answers2