Aiutami a capire il modulo di registrazione di Python ei suoi gestori

Question

Mi manca davvero qualcosa di basilare sul modulo di registrazione di Python.

Nel seguente codice, creo un oggetto logger (log) e aggiungo due gestori. Uno con livello "INFO" e uno con livello "ATTENZIONE". Entrambi dovrebbero stampare su stdout. Mi aspetto che la chiamata a log.info(msg) comporterà una copia di msg nel mio stdout e la chiamata a log.warn(msg) potrebbe produrre in due copie di msg stampate sul mio stdout. Ecco il codice:

import logging 
import sys 


logging.basicConfig() 
log = logging.getLogger('myLogger') 
log.handlers = [] 
h1 = logging.StreamHandler(sys.stdout) 
h1.level = logging.INFO 
h1.formatter = logging.Formatter('H1 H1 %(message)s ') 
h2 = logging.StreamHandler(sys.stdout) 
h2.level = logging.WARNING 
h2.formatter = logging.Formatter('H2 H2 %(message)s') 
log.addHandler(h1) 
log.addHandler(h2) 

print 'log.level == %s'%logging.getLevelName(log.level) 
print 'log.info' 
log.info('this is some info') 
print 'done' 
print 'log.warn' 
log.warn('this is a warning') 
print 'done' 

L'uscita è davvero molto strano per me. La chiamata .info non produce alcun effetto visivo. Tuttavia, la chiamata a warn produce due copie di msg stampate su stdout (che è OK), ma anche una copia stampata su stderr (perché?). Questo è l'output del codice sopra. Nota la formattazione dell'ultima riga in questo output. Questa riga è stampata su stderr.

log.level == NOTSET 
log.info 
done 
log.warn 
H1 H1 this is a warning 
H2 H2 this is a warning 
done 
WARNING:myLogger:this is a warning 

Quindi le mie domande sono:

1. perché fa la mia chiamata a info risultato in nessuna uscita, nonostante il fatto che il livello h1 s' è impostato su INFO?
2. perché la mia chiamata a warn genera un output aggiuntivo su stderr?

Answer 1

Ci sono due cose che dovete sapere:

1. Il logger di root è inizializzato con un livello di WARNING.

   Qualsiasi messaggio di registro che raggiunge un registratore viene scartato se il suo livello è inferiore al livello del registratore. Se il livello di un logger non è impostato, prenderà il suo "livello effettivo" dal suo registratore principale. Quindi se il logger di root ha un livello di WARNING, tutti i logger hanno un livello effettivo predefinito di WARNING.Se non lo si configura diversamente, tutti i messaggi di registro con un livello inferiore verranno scartati.

2. Quando si chiama basicConfig(), il sistema imposta automaticamente un StreamHandler nel logger principale che viene stampato sul flusso di errore standard.

   Quando il programma stampa i suoi messaggi di log, ci sono in realtà tre gestori: i due che hai aggiunto, che hanno i propri livelli, e uno dal sistema che stamperà qualsiasi messaggio non respinta da il suo logger. Ecco perché ottieni la linea

   WARNING:myLogger:this is a warning 
   

   Viene dal logger di sistema. Non lo fa per il messaggio di livello INFO, perché come discusso in precedenza, il logger di root è configurato per rifiutare tali messaggi per impostazione predefinita.

   Se non si desidera questa uscita, non chiamare basicConfig().

Ulteriori approfondimenti: http://docs.python.org/howto/logging.html

Answer 2

Esistono attualmente cinque livelli di registrazione: debug, informazioni, avviso, errore e critico. Vedo che quando configuri il tuo logger non stai impostando esplicitamente il tuo livello - credo che il logger possa impostare di default l'avviso se il livello non è impostato.

Per quanto riguarda il motivo per cui viene stampato più volte per l'avviso, credo che questo sia dovuto alla creazione di due gestori per informazioni & avviso. Quello che succede è che il logger scende a cascata a dismisura da warning -> info -> debug, chiamando il gestore per ciascuno di essi. Poiché il tuo livello è impostato su avviso, il gestore informazioni viene ignorato. Inoltre, credo che i messaggi di avvertimento siano normalmente scritti su sys.stderr.

provare quanto segue:

logging.basicConfig(level=logging.INFO) 

Vedi anche:

• Logging module docs
• Logging basic example