Hoe u logging gebruikt in Python 3

Inleiding

De logging-module maakt deel uit van de standaard Python-bibliotheek en biedt bijhouden van gebeurtenissen die plaatsvinden tijdens het uitvoeren van software. U kunt logboekoproepen toevoegen aan uw code om aan te geven welke gebeurtenissen hebben plaatsgevonden.

De logging-module staat zowel diagnostische logging toe die gebeurtenissen registreert die verband houden met de werking van een toepassing, als audit logging die de gebeurtenissen van transacties van een gebruiker registreert voor analyse. Het wordt vooral gebruikt om gebeurtenissen naar een bestand te registreren.

Vereisten

U moet Python 3 geïnstalleerd hebben en een programmeeromgeving op uw computer of server hebben ingesteld. Als u geen programmeeromgeving hebt ingesteld, kunt u verwijzen naar de installatie- en instelgidsen voor een lokale programmeeromgeving of voor een programmeeromgeving op uw server die geschikt is voor uw besturingssysteem (Ubuntu, CentOS, Debian, enz.).

Waarom de logging-module gebruiken

De logging-module houdt een ​​registratie bij van de gebeurtenissen die zich voordoen binnen een programma, waardoor het mogelijk is om uitvoer te zien die verband houdt met een van de gebeurtenissen die zich gedurende de runtime van een stuk software voordoen.

Je bent misschien meer vertrouwd met het controleren of gebeurtenissen plaatsvinden door de print()-verklaring te gebruiken in je code. De print()-verklaring biedt een eenvoudige manier om je code te debuggen om problemen op te lossen. Hoewel het invoegen van print()-verklaringen verspreid over je code de uitvoerstroom en de huidige status van je programma kan volgen, blijkt deze oplossing minder onderhoudbaar te zijn dan het gebruik van de logging-module om een paar redenen:

• Het wordt moeilijk om onderscheid te maken tussen debuguitvoer en normale programma-uitvoer omdat deze twee worden gemengd
• Bij het gebruik van print()-verklaringen verspreid over de code is er geen efficiënte manier om degene uit te schakelen die debuguitvoer levert
• Het wordt moeilijk om alle print()-verklaringen te verwijderen wanneer je klaar bent met debuggen
• Er is geen logboekregistratie die direct beschikbare diagnostische informatie bevat

Het is een goed idee om in de gewoonte te komen om de logging-module in je code te gebruiken, aangezien dit meer geschikt is voor toepassingen die verder gaan dan kleine Python-scripts en een duurzame aanpak biedt voor debuggen.

Omdat logs u gedrag en fouten in de loop van de tijd kunnen tonen, kunnen ze u ook een beter totaalbeeld geven van wat er gaande is in uw applicatieontwikkelingsproces.

Debugberichten naar Console Afdrukken

Als u gewend bent om de print()-verklaring te gebruiken om te zien wat er gebeurt in een programma, bent u misschien gewend om een programma te zien dat een klasse definieert en objecten instantieert die iets genereren zoals dit:

class Pizza():
    def __init__(self, name, price):
        self.name = name
        self.price = price
        print("Pizza created: {} (${})".format(self.name, self.price))

    def make(self, quantity=1):
        print("Made {} {} pizza(s)".format(quantity, self.name))

    def eat(self, quantity=1):
        print("Ate {} pizza(s)".format(quantity, self.name))

pizza_01 = Pizza("artichoke", 15)
pizza_01.make()
pizza_01.eat()

pizza_02 = Pizza("margherita", 12)
pizza_02.make(2)
pizza_02.eat()

De bovenstaande code heeft een __init__-methode om de naam en prijs van een object van de Pizza-klasse te definiëren. Het heeft vervolgens twee methoden, één genaamd make() voor het maken van pizza’s, en één genaamd eat() voor het eten van pizza’s. Deze twee methoden nemen de parameter van aantal, die is geïnitialiseerd op 1.

Lat we nu het programma uitvoeren:

python pizza.py

We zullen de volgende uitvoer ontvangen:

Output
Pizza created: artichoke ($15)
Made 1 artichoke pizza(s)
Ate 1 pizza(s)
Pizza created: margherita ($12)
Made 2 margherita pizza(s)
Ate 1 pizza(s)

Terwijl de print()-verklaring ons in staat stelt te zien dat de code werkt, kunnen we in plaats daarvan de logging-module gebruiken.

Laten we de print()-verklaringen in de hele code verwijderen of uitcommentariëren, en import logging toevoegen aan de bovenkant van het bestand:

import logging


class Pizza():
    def __init__(self, name, value):
        self.name = name
        self.value = value
...

De logging-module heeft een standaardniveau van WARNING, wat een niveau boven DEBUG is. Omdat we de logging-module gaan gebruiken voor debugging in dit voorbeeld, moeten we de configuratie aanpassen zodat het niveau van logging.DEBUG informatie naar de console retourneert voor ons. We kunnen dat doen door de volgende regel onder de importverklaring toe te voegen:

import logging

logging.basicConfig(level=logging.DEBUG)


class Pizza():
...

Dit niveau van logging.DEBUG verwijst naar een constant integerwaarde die we in de bovenstaande code gebruiken om een drempelwaarde in te stellen. Het niveau van DEBUG is 10.

Nu zullen we alle print()-verklaringen vervangen door logging.debug()-verklaringen. In tegenstelling tot logging.DEBUG, dat een constante is, is logging.debug() een methode van de logging-module. Bij het werken met deze methode kunnen we dezelfde tekenreeks gebruiken die aan print() wordt doorgegeven, zoals getoond in het volgende:

import logging

logging.basicConfig(level=logging.DEBUG)


class Pizza():
    def __init__(self, name, price):
        self.name = name
        self.price = price
        logging.debug("Pizza created: {} (${})".format(self.name, self.price))

    def make(self, quantity=1):
        logging.debug("Made {} {} pizza(s)".format(quantity, self.name))

    def eat(self, quantity=1):
        logging.debug("Ate {} pizza(s)".format(quantity, self.name))

pizza_01 = Pizza("artichoke", 15)
pizza_01.make()
pizza_01.eat()

pizza_02 = Pizza("margherita", 12)
pizza_02.make(2)
pizza_02.eat()

Op dit punt, wanneer we het programma uitvoeren met het python pizza.py-commando, ontvangen we deze uitvoer:

Output
DEBUG:root:Pizza created: artichoke ($15)
DEBUG:root:Made 1 artichoke pizza(s)
DEBUG:root:Ate 1 pizza(s)
DEBUG:root:Pizza created: margherita ($12)
DEBUG:root:Made 2 margherita pizza(s)
DEBUG:root:Ate 1 pizza(s)

De logboekberichten hebben het ernstniveau DEBUG, evenals het woord root erin verwerkt, wat verwijst naar het niveau van uw Python-module. De logging-module kan worden gebruikt met een hiërarchie van loggers die verschillende namen hebben, zodat u voor elk van uw modules een andere logger kunt gebruiken.

Bijvoorbeeld, u kunt loggers instellen die gelijk zijn aan verschillende loggers met verschillende namen en verschillende uitvoer:

logger1 = logging.getLogger("module_1")
logger2 = logging.getLogger("module_2")

logger1.debug("Module 1 debugger")
logger2.debug("Module 2 debugger")

Output
DEBUG:module_1:Module 1 debugger
DEBUG:module_2:Module 2 debugger

Nu we begrijpen hoe we de logging-module kunnen gebruiken om berichten naar de console te printen, gaan we verder met het gebruiken van de logging-module om berichten naar een bestand te printen.

Berichten naar een bestand loggen

Het primaire doel van de logging-module is om berichten naar een bestand te loggen in plaats van naar de console. Het bijhouden van een bestand met berichten geeft u gegevens in de loop van de tijd die u kunt raadplegen en kwantificeren, zodat u kunt zien welke wijzigingen in uw code moeten worden aangebracht.

Om te beginnen met loggen naar een bestand, kunnen we de logging.basicConfig()-methode aanpassen om een filename-parameter op te nemen. In dit geval noemen we het bestand test.log:

import logging

logging.basicConfig(filename="test.log", level=logging.DEBUG)


class Pizza():
    def __init__(self, name, price):
        self.name = name
        self.price = price
        logging.debug("Pizza created: {} (${})".format(self.name, self.price))

    def make(self, quantity=1):
        logging.debug("Made {} {} pizza(s)".format(quantity, self.name))

    def eat(self, quantity=1):
        logging.debug("Ate {} pizza(s)".format(quantity, self.name))

pizza_01 = Pizza("artichoke", 15)
pizza_01.make()
pizza_01.eat()

pizza_02 = Pizza("margherita", 12)
pizza_02.make(2)
pizza_02.eat()

Het bovenstaande codefragment is hetzelfde als in de vorige sectie, behalve dat we nu de bestandsnaam hebben toegevoegd waar het logboek naartoe moet worden afgedrukt. Zodra we de code uitvoeren met het python pizza.py-commando, moeten we een nieuw bestand in onze directory hebben met de naam test.log.

Laten we het bestand test.log openen met nano (of de teksteditor van jouw keuze):

nano test.log

Wanneer het bestand opent, zullen we het volgende ontvangen:

DEBUG:root:Pizza created: artichoke ($15)
DEBUG:root:Made 1 artichoke pizza(s)
DEBUG:root:Ate 1 pizza(s)
DEBUG:root:Pizza created: margherita ($12)
DEBUG:root:Made 2 margherita pizza(s)
DEBUG:root:Ate 1 pizza(s)

Dit is vergelijkbaar met de console-uitvoer die we in de vorige sectie tegenkwamen, behalve dat het nu in het bestand test.log staat.

Laten we het bestand sluiten met CTRL + x en teruggaan naar het bestand pizza.py zodat we de code kunnen aanpassen.

We zullen veel van de code hetzelfde houden, maar de parameters aanpassen in de twee instanties van pizza, pizza_01 en pizza_02:

import logging

logging.basicConfig(filename="test.log", level=logging.DEBUG)


class Pizza():
    def __init__(self, name, price):
        self.name = name
        self.price = price
        logging.debug("Pizza created: {} (${})".format(self.name, self.price))

    def make(self, quantity=1):
        logging.debug("Made {} {} pizza(s)".format(quantity, self.name))

    def eat(self, quantity=1):
        logging.debug("Ate {} pizza(s)".format(quantity, self.name))

# Pas de parameters van het pizza_01 object aan
pizza_01 = Pizza("Sicilian", 18)
pizza_01.make(5)
pizza_01.eat(4)

# Pas de parameters van het pizza_02 object aan
pizza_02 = Pizza("quattro formaggi", 16)
pizza_02.make(2)
pizza_02.eat(2)

Met deze wijzigingen laten we het programma opnieuw uitvoeren met het commando python pizza.py.

Zodra het programma is uitgevoerd, kunnen we ons bestand test.log opnieuw openen met nano:

nano test.log

Als we het bestand bekijken, zullen we zien dat er verschillende nieuwe regels zijn toegevoegd en dat de vorige regels van de laatste keer dat het programma werd uitgevoerd behouden zijn gebleven:

DEBUG:root:Pizza created: artichoke ($15)
DEBUG:root:Made 1 artichoke pizza(s)
DEBUG:root:Ate 1 pizza(s)
DEBUG:root:Pizza created: margherita ($12)
DEBUG:root:Made 2 margherita pizza(s)
DEBUG:root:Ate 1 pizza(s)
DEBUG:root:Pizza created: Sicilian ($18)
DEBUG:root:Made 5 Sicilian pizza(s)
DEBUG:root:Ate 4 pizza(s)
DEBUG:root:Pizza created: quattro formaggi ($16)
DEBUG:root:Made 2 quattro formaggi pizza(s)
DEBUG:root:Ate 2 pizza(s)

Hoewel deze informatie zeker nuttig is, kunnen we het logboek informatiever maken door extra LogRecord-attributen toe te voegen. Voornamelijk zouden we graag een leesbare tijdstempel toevoegen die ons vertelt wanneer de LogRecord is gemaakt.

We kunnen dat attribuut toevoegen aan een parameter genaamd format, waarbij we er naar verwijzen zoals getoond in de tabel met de string %(asctime)s. Daarnaast, om de naam van het DEBUG-niveau te behouden, moeten we de string %(levelname)s toevoegen en om de berichtstring te behouden die we de logger vragen af ​​te drukken, voegen we %(message)s toe. Elk van deze attributen zal worden gescheiden door een dubbelepunt, zoals getoond in de toegevoegde code:

import logging

logging.basicConfig(
    filename="test.log",
    level=logging.DEBUG,
    format="%(asctime)s:%(levelname)s:%(message)s"
    )


class Pizza():
    def __init__(self, name, price):
        self.name = name
        self.price = price
        logging.debug("Pizza created: {} (${})".format(self.name, self.price))

    def make(self, quantity=1):
        logging.debug("Made {} {} pizza(s)".format(quantity, self.name))

    def eat(self, quantity=1):
        logging.debug("Ate {} pizza(s)".format(quantity, self.name))

pizza_01 = Pizza("Sicilian", 18)
pizza_01.make(5)
pizza_01.eat(4)

pizza_02 = Pizza("quattro formaggi", 16)
pizza_02.make(2)
pizza_02.eat(2)

Wanneer we de bovenstaande code uitvoeren met de toegevoegde attributen met het python pizza.py-commando, krijgen we nieuwe regels toegevoegd aan ons test.log-bestand die de leesbare tijdstempel bevatten, naast de niveau-naam van DEBUG en de bijbehorende berichten die als strings aan de logger worden doorgegeven.

DEBUG:root:Pizza created: Sicilian ($18)
DEBUG:root:Made 5 Sicilian pizza(s)
DEBUG:root:Ate 4 pizza(s)
DEBUG:root:Pizza created: quattro formaggi ($16)
DEBUG:root:Made 2 quattro formaggi pizza(s)
DEBUG:root:Ate 2 pizza(s)
2021-08-19 23:31:34,484:DEBUG:Pizza created: Sicilian ($18)
2021-08-19 23:31:34,484:DEBUG:Made 5 Sicilian pizza(s)
2021-08-19 23:31:34,484:DEBUG:Ate 4 pizza(s)
2021-08-19 23:31:34,484:DEBUG:Pizza created: quattro formaggi ($16)
2021-08-19 23:31:34,484:DEBUG:Made 2 quattro formaggi pizza(s)
2021-08-19 23:31:34,484:DEBUG:Ate 2 pizza(s)

Afhankelijk van uw behoeften wilt u mogelijk extra LogRecord-attributen gebruiken in uw code om uw programmabestandenlogboeken relevant te maken voor u.

Het loggen van debug- en andere berichten in afzonderlijke bestanden geeft u een alomvattend inzicht in uw Python-programma in de loop van de tijd, waardoor u de mogelijkheid heeft om problemen op te lossen en uw code aan te passen op een manier die wordt geïnformeerd door het historische werk dat in het programma is gestoken, evenals de gebeurtenissen en transacties die plaatsvinden.

Tabel van Logniveaus

Als ontwikkelaar kunt u een niveau van belang toewijzen aan het evenement dat wordt vastgelegd in de logger door een ernstniveau toe te voegen. De ernstniveaus worden weergegeven in de onderstaande tabel.

Logniveaus zijn technisch gezien integers (een constante) en ze zijn allemaal in stappen van 10, beginnend met NOTSET dat de logger initialiseert op de numerieke waarde van 0.

U kunt ook uw eigen niveaus definiëren ten opzichte van de vooraf gedefinieerde niveaus. Als u een niveau definieert met dezelfde numerieke waarde, overschrijft u de naam die is geassocieerd met die waarde.

De volgende tabel toont de verschillende niveaunamen, hun numerieke waarde, welke functie u kunt gebruiken om het niveau aan te roepen, en waar dat niveau voor wordt gebruikt.

De logging-module stelt het standaardniveau in op WARNING, dus WARNING, ERROR en CRITICAL worden allemaal standaard gelogd. In het bovenstaande voorbeeld hebben we de configuratie aangepast om het niveau DEBUG op te nemen met de volgende code:

logging.basicConfig(level=logging.DEBUG)

U kunt meer lezen over de commando’s en het werken met de debugger in de officiële logging documentatie.

Conclusie

Debuggen is een belangrijke stap in elk softwareontwikkelingsproject. De logging-module is onderdeel van de standaard Python-bibliotheek, biedt het bijhouden van gebeurtenissen die optreden tijdens het uitvoeren van software, en kan deze gebeurtenissen uitvoeren naar een apart logbestand om je in staat te stellen bij te houden wat er gebeurt terwijl je code wordt uitgevoerd. Dit geeft je de mogelijkheid om je code te debuggen op basis van het begrijpen van de verschillende gebeurtenissen die optreden tijdens het uitvoeren van je programma in de loop van de tijd.