Debugging in Django

die print-Funktion

Der einfachste und unkompliziertes Weg, Teile des Codes zu testen oder mal eine kleine Testausgabe zu machen, ist die print-Funktion. Führen wir print in einer View aus, sehen wir das Ergebnis in der Konsole, dh. es wird uns direkt in die Ausgabe des Runservers gespielt. Allerdings sollte man darauf achten, dass die prints nicht im Produktivsystem aktiv sind. Alles in allem also nicht unbedingt das ideale Werkzeug, um Django Code zu debuggen.

Es ist auch zu beachten, dass print standardmäßig immer auf stdout druckt, dieses Verhalten aber nicht immer erwünscht ist.

File-Deskriptoren mit Bedeutung: stdout, stderr, stdin

Unter Linux existieren drei Standard-Datenströme für die Ein- und Ausgabe. stdin ist die Standard-Eingabe, mit der Daten in ein Programm eingegeben werden können.

Wenn wir auf der Kommandozeile ein Python-Programm starten und über input() Daten einlesen, ist das die Standardeigabe. stdin ist ein File-Deskriptor mit der Nummer 0.

Die Standard-Ausgabe nennt sich stdout und ist mit der Nummer 1 ein weiterer File-Deskriptor. Beim Aufruf der print()-Funktion wird standardmäßig nach stdout gedruckt.

Zuletzt gibt es noch den File-Deskriptor stderr mit der Nummer 2. Wer noch nie von diesen drei Standard-Datenströmen gehört hat, hat vielleicht an dieser Stelle die Frage, was das nun ist.

In Python könnten wir eine print-Funktion auf die folgende Weise dazu bewegen, nach stderr zu drucken:

print("Fehler!", file=sys.stderr)

Zuerst mal passiert nichts weiter, führen wir die Funktion so aus, wird uns auf der Konsole eben „Fehler!“ ausgegeben. Also, was soll das dann?

Wir könnten ein anderes Programm dazu bewegen, alles, was nach stderr geprintet wird, in eine Datei zu schreiben, während alles andere, was nach stdout gedruckt wird, auf der Konsole auszugeben. Im folgenden ein Beispiel-Skript, was gerne ausprobiert werden kann.

# stderr_test.py
import sys

print("das hier wird nach stdout gedruckt")
print("das hier nach stderr", file=sys.stderr)

Ausführen kann man das Programm dann auf der Konsole:

python stderr_test.py 2> error_log
python stderr_test.py 1> output_file 2> error_log
python stderr_test.py 1>> output_file 2>> error_log

2> leitet alle Ausgaben an stderr in eine Datei namens error_log um, während die andere print-Ausgabe auf der Konsole ausgegeben wird , bzw via 1> in die output_file geschrieben wird.

Im dritten Beispiel nutzen wir den Doppelpfeil >>, um die Daten nur anzuhängen und nicht zu überschreiben.

Allerdings sollten wir uns hüten, in Django diese Angabe sys.stderr manuell zu machen. Das Logging-Modul von Django hat dieses Verhalten out-of-the-box.

Mehr zu dem Thema:: https://de.wikipedia.org/wiki/Standard-Datenstr%C3%B6me#Standardeingabe_(stdin)

Logger

Wir können das Python-Logging Modul unkompliziert in Django nutzen.

Dazu öffnen wir erstmal die Datei event_manager/event_manager/settings/base.py und definieren die LOGGING-Konfiguration:

LOGGING = {
    "version": 1,
    "disable_existing_loggers": False,
    "formatters": {
        "simple": {
            "format": "%(levelname)s %(module)s %(asctime)s %(pathname)s%(message)s"
        },
    },
    "handlers": {
        # ins django_log file kommen generell nur mindestens warnings
        "django_log": {
            "level": "WARNING",
            "class": "logging.FileHandler",
            "filename": BASE_DIR / "django_errors.log",
            "formatter": "simple",
        },
        # Auf die console können wir auch Infos schreiben
        "console": {
            "class": "logging.StreamHandler",
            "formatter": "simple",
            "level": "INFO",
        },
    },
    "root": {"handlers": ["console"], "level": "WARNING"},
    # um doppeltes Loggen mit dem Root Logger zu vermeiden, setzen wir
    "loggers": {
        "django": {
            "handlers": ["django_log", "console"],
            "level": "INFO",
            "propagate": False,
        },
        "eventmanager.events": {
            "handlers": ["django_log"],
            "level": "WARNING",
            "propagate": False,
        },
    },
}

Wir haben in den settings/base.py also das Logging für das System festgelegt (nur ein Beispiel). Wir können das Logging natürlich in den Settings für Produktivsystem oder lokales System überschreiben.

Formatters

Wir haben einen einfachen Formatierer namens simple festgelegt. Unter formatters erstellt man die Formatierungen, die man in seinen Log Files benögtigt.

Handler

Handler sind der Teil des Loggings, der mit den Debug-Infos konkret was macht, zum Beispiel die Fehler auf die Konsole streamen oder in ein rotierendes Log-File zu schreiben. Wir haben 2 Handler festgelegt:

django_log Das django-Log ist für die Ausgaben von Django da und auch das schreiben wir in eine Datei. Wir wollen hier nur mindestens Warnings sehen. Es nutzt den simple-Formatter.

console Auf der Console können wir alle Infos schreiben. Es nutzt den simple-Formatter.

Logger

django Der Django-Logger ist der Haupt-Logger von Django. Wir könnten ihn hier auch deaktiveren, aber das wollen wir nicht. Wir wollen alles, was der Django-Logger von sich gibt, an den django_log-Handler weiterreichen. Und der schreibt ja alles, was mindestens den Status WARNING hat, in eine Log-Datei.

Auf der Konsole lassen wir auch Django-Infos zeigen, die sind ja manchmal auch ganz aufschlußreich.

eventmanager.events Unsere Events-App soll Warnings in das debug_log schreiben. Wir brauche nicht für jede App einen Eintrag. Wenn wir keinen Eintrag angeben, wir der Django-Logger die Logging-Messages verarbeiten. Es macht nur Sinn, wenn man speziell für diese App Handler oder Levels nutzen will.

Mehr zu den Django-Loggern hier: https://docs.djangoproject.com/en/stable/logging/#django-logging-extensions

Root

Nicht alle Fehler, die auftreten, kommen direkt von Django oder einer Django-App. Auch Python oder eventuelle Abhängigkeiten senden Fehler und diese werden standardmäßig auf die Console weitergeleitet. Mit dem root Eintrag legen wir fest, dass alle diese Fehler ab dem WARNING-Level auf der Konsole angzeigt werden sollen.

Wenn wir die Logging-Ausgaben in der dev-Settings anders haben wollen, können wir diese dort nach Lust und Laune überschreiben

from debug_toolbar.panels.logging import collector

# Einen Handler einrichten, damit die Daten an die Debug-Toolbar gestreamt werden.
LOGGING["handlers"].update({
    "djdt_log": {
        "level": "DEBUG",
        "class": "debug_toolbar.panels.logging.ThreadTrackingHandler",
        "collector": collector,
    },
})

LOGGING["loggers"].update({
    "eventmanager.events": {
        "handlers": ["django_log", "console", "djdt_log"],
        "level": "DEBUG",
        "propagate": False,
    },
    "django": {
        "handlers": ["django_log", "console", "djdt_log"],
        "level": "WARNING",
    },
    # faker spammt die Logs mit Infos beim Testen wegen UserFactory
    "faker": {"level": "ERROR", "propagate": True},
    "factory": {"level": "ERROR", "propagate": True},
})

Code debuggen

Wir können den Logger im Code so nutzen:

import logging
logger = logging.getLogger(__name__)

def categories(request):
    """Funktion View, die alle Kategorien auflistet.
    http://127.0.0.1:8000/events/categories
    """
    logger.info(f"verwendete HTTP-Methode: {request.method}")
    categories_list = Category.objects.all()
    logger.debug(f"Anzahl Kategorien: {categories_list.count()}")
    return render(request, "events/categories.html",
                  {"categories": categories_list})

python Debugger

Für gezieltere Maßnahmen können wir auch den Python Debugger pdb nutzen. Die Vorgehensweise ist ziemlich klassisch. Wir setzen einen Breakpoint in einer View, rufen die Page auf und auf der Konsole wird der pdb-Debugger aufgeführt und wartet auf Eingabe. Erst, wenn der Debugger mit quit wieder verlassen wird, wird auch die Page gerendert.

Breakpoint

breakpoint in Funktion setzen

def categories(request):
    # breakpoint vor der Abfrage setzen um später categories zu untersuchen
    breakpoint()
    categories = Category.objects.all()

    return render(
        request,
        "events/categories.html",
        {"categories": categories},
    )

View aufrufen

http://127.0.0.1:8000/categories

auf der Konsole öffnet sich der Debugger pdb

> d: \event_manager\events\views.py(36)list_categories()
-> categories = Category.objects.all()
(Pdb) categories
*** NameError: name 'categories' is not defined
(Pdb) n
> d: \win\stuff\web\django_educational_projects\event_manager\events\views.py(38)list_categories()
-> return render(
(Pdb) categories
< QuerySet [ < Category: Freizeit > , < Category: Kochen > , < Category: Sport > , < Category: Talk > ] >
(Pdb) ll
 32 def list_categories(request):
 33 print("verwendete HTTP-Methode: ", request.method)
 34         logger.debug("Ochse")
 35         breakpoint()
 36         categories=Category.objects.all()
 37
 38 -> return render(
 39             request,
 40             "events/category_list_simple.html",
 41             {"categories": categories},
 42)
(Pdb) n
> d: \win\stuff\web\django_educational_projects\event_manager\events\views.py(39)list_categories()
-> request,
(Pdb) ll
 32 def list_categories(request):
 33 print("verwendete HTTP-Methode: ", request.method)
 34         logger.debug("Ochse")
 35         breakpoint()
 36         categories=Category.objects.all()
 37
 38 return render(
 39 -> request,
 40             "events/category_list_simple.html",
 41             {"categories": categories},
 42)
(Pdb) n
> d: \win\stuff\web\django_educational_projects\event_manager\events\views.py(40)list_categories()
-> "events/category_list_simple.html",
(Pdb) request
< WSGIRequest: GET '/events/categories/' >
(Pdb) ll
 32 def list_categories(request):
 33 print("verwendete HTTP-Methode: ", request.method)
 34         logger.debug("Ochse")
 35         breakpoint()
 36         categories=Category.objects.all()
 37
 38 return render(
 39             request,
 40 -> "events/category_list_simple.html",
 41             {"categories": categories},
 42)
(Pdb)

pdb - ein Klassiker

Der Python-Debugger pdb ist fester Bestandteil der Python Standard-Bibliothek und ein mächtiges Werkzeug bei der interaktiven Inspektion von Python - Code. Nicht so komfortabel wie manche IDE, aber mit ein bisschen Übung leicht zu beherrschen.

Die wichtigsten Kommandos:
`l`	liste Code oben und unterhalb aktueller Zeile (11 Zeilen)
`ll`	liste den Quellcode der akutellen Funktion (oder Frame)
`s`	Nächste Zeile und springe in Funktion (wenn verfügbar)
`n`	nächste Zeile und springe NICHT in Funktion (wenn verfügbar)
`c`	continue und springe zum nächsten Breakpoint
`var`	Inhalt der Variable var anzeigen
`q`	quit

Logging mit Rollbar

Rollbar ist eine kommerzielle Error-Tracking Software, die in Django unkompliziert eingesetzt werden kann und alle Fehler/Exceptions an einen entfernten Server sendet. Rollbar bietet leichte Integration und ein komfortables Dashboard. Rollbar bietet überdies ein SDK für Django, es muss nur mit pip installiert und in die settings.py importiert werden.

Rollbar ist nicht dafür da, falsche Formulareingaben oder ähnliches zu tracken, sondern Ausnahmen wie 404-Fehler und ähnliches.

Rollbar Account erstellen

Für kleine Websites und Privatanwender bietet Rollbar einen Gratis-Account an. Mehr unter rollbar.com.

Rollbar installieren

Fügen wir die Rollbar der requirements.in hinzu, kompilieren und syncen:

...
rollbar

(eventenv)  pip-compile requirements.in
(eventenv)  pip-sync requirements.txt requirements-dev.txt

Settings

Wenn ein Account angelegt wurde, kann man der entsprechende ROLLBAR_TOKEN in das .env-File eintragen und in den Settings nutzen. Dazu in der event_manager/.env folgenden Eintrag hinzufügen:

In den Settings muss die Middleware und die Konfigurationsvariablen eingetragen werden.

import rollbar

# anderer Code

MIDDLEWARE = [
    # andere Middleware
    "rollbar.contrib.django.middleware.RollbarNotifierMiddleware",
]

# anderer Code

ROLLBAR = {
    "access_token": env("ROLLBAR_TOKEN"),
    "environment": "development" if DEBUG else "production",
    "root": BASE_DIR,
}
rollbar.init(**ROLLBAR)

Das war’s, mehr muss man nicht machen, um ein professionelles Error-Tracking-System zu betreiben. Natürlich lassen sich weitere Umgebungen, Projekte und Kollaborationen einstellen.