Il y a peu, je me suis mis à utiliser logging
pour debugger mes scripts de débutant.
Si comme moi vous avez l’habitude de mettre des print
partout pour trouver l’origine d’un problème, et qu’ensuite vous avez passé de longues longues longues minutes/heures à traquer ces foutus print
pour dépolluer la sortie console, jetez un oeil à écrire des logs en python.
Après quelques (minutes/heures/jours) de prise en main (vite, quoi…), on se demande comment on a fait pour s’en passer si longtemps. C’est simple, je n’utilise plus les touches “p”, “r”, “i”, “n” et “t” de mon clavier. Elles sont toutes propres.
En plus, logging
m’a ouvert de nouvelles perspectives, parmi lesquelles la possibilité d’envoyer les logs par mail. Pas besoin de tout recevoir par mail, mais si ce foutu script de m%@rde pouvait m’envoyer un email quand il plante avec la source détaillé du problème, ce serait super.
Admettons que vous vouliez vérifier que les pensées qui vous traversent l’esprit sont safe for work. Vous écrivez un script génial qui fait le boulot.
Comme vous commencez à savoir y faire en python, vous avez même écrit votre propre exception à vous tout seul…
class NotSafeForWorkError(Exception):
"""
Exception soulevée si une pensée est NSFW
"""
def __init__(self, msg):
self.msg = u"Danger! %s est NSFW." % msg
def __str__(self):
return self.msg.encode("utf-8")
# liste des pensées proscrites
# (échantillon, elle est beaucoup plus longue que ça en réalité)
NSFW = ["cul", "seins", "sametmax"]
# boucle de censure qui soulève une exception si une pensée déconne
for pensee in ["pause", "pipi", "sametmax"]:
if pensee in NSFW:
raise NotSafeForWorkError(pensee)
print u"%s est SFW" % pensee
#sortie:
## pause est SFW
## pipi est SFW
## Traceback (most recent call last):
## File "censure_setm3.py", line 30, in
## raise NotSafeForWorkError(pensee)
## __main__.NotSafeForWorkError: Danger! sametmax est NSFW.
Ça marche du tonnerre! C’est là que vous vous dites que ce serait bien si le script envoyait le traceback par email à votre psy pour le prévenir que vous avez déconné.
A la maison, vous avez lu l’article de Sam sur les logs post mortem. Ça a l’air facile à faire.
Vous créez d’abord un logger qui enverra les logs de niveau critique par mail:
import logging
from logging.handlers import SMTPHandler
nom_loggeur = "test_nsfw"
# On crée un logger et on met le niveau à critique:
# il ne tiendra compte que des logs de ce niveau
logger = logging.getLogger(nom_loggeur)
logger.setLevel(logging.CRITICAL)
# On crée le handler en lui passant les paramètres
# nécessaires à l'envoi d'un email
mail_handler = SMTPHandler(
# Host et port
('SMTP.GMAIL.COM', 587),
# From
"MOI@GMAIL.COM",
# To (liste)
["QUELQU.UN@QUELQUE.PART"],
# Sujet du message
"Erreur critique dans %s" % nom_loggeur,
# pour l'authentification
credentials = ("MONEMAIL@GMAIL.COM", "MONSUPERPASSWORD"),
secure = ())
# On met le handler à "critique".
# Il enverra donc par mail les messages de ce niveau
mail_handler.setLevel(logging.CRITICAL)
# On définit un formatter: date, nom du logger, niveau, message
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
# On associe le formatter au handler:
# c'est lui qui formatera les logs de ce handler
mail_handler.setFormatter(formatter)
# ... et on associe le handler au logger:
# il utilisera ce handler, qui émettra les logs critiques
logger.addHandler(mail_handler)
Ensuite vous redéfinissez sys.excepthook de manière à ce que l’exception soit logguée. La fonction convertit le traceback en string, la loggue au niveau critique et laisse l’exception continuer son chemin.
import sys
# la fonction qui remplacera sys.excepthook
def en_cas_de_plantage(type_except, value, tb):
# Traceback permettra de formater l'exception.
import traceback
# Mise en forme de l'exception. Retourne la trace
# sous forme de str avec numéros de lignes et tout
trace = "".join(traceback.format_exception(type_except, value, tb))
# On loggue l'exception au niveau "critique",
# elle sera donc envoyée par email
logger.critical(u"Erreur inattendue:\n%s", trace)
# ... et on laisse le script se planter...
sys.__excepthook__(type_except, value, tb)
# on remplace sys.excepthook, et le tour est joué
sys.excepthook = en_cas_de_plantage
Et voilà. Vous lancez le script, il se casse la gueule dès qu’il rencontre “sametmax”, votre psy reçoit un email avec le traceback, c’est cool.
Sauf que…
Si au moment de la création de mail_handler, vous passez comme sujet à SMTPHandler:
u"%s s'est planté" % nom_loggeur
ou que dans votre fonction “en_cas_de_plantage” vous mettez:
logger.critical(u"Bébé a encore glissé dans son caca:\n%s", trace)
… autrement dit si vous avez une chaîne unicode qui ne peut pas être encodée en ascii, ça va pas marcher:
Traceback (most recent call last):
File "envoie_mail_on_crash.py", line 84, in emit
smtp.sendmail(self.fromaddr, self.toaddrs, msg)
File "/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/smtplib.py", line 734, in sendmail
(code, resp) = self.data(msg)
File "/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/smtplib.py", line 501, in data
self.send(q)
File "/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/smtplib.py", line 321, in send
self.sock.sendall(str)
File "/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/ssl.py", line 229, in sendall
v = self.send(data[count:])
File "/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/ssl.py", line 198, in send
v = self._sslobj.write(data)
UnicodeEncodeError: 'ascii' codec can't encode character u'\xe9' in position 62: ordinal not in range(128)
Logged from file envoie_mail_on_crash.py, line 163
D’où l’on déduit qu’il y a une tentative foirée d’encodage d’une chaîne unicode en ascii par la méthode “write” de ce mystérieux _sslobj, et que c’est une méthode “emit” quelque part dans handlers.py qui lui a passé la chaîne.
Fuck! Investiguons. Et essayons de régler ça par le haut de la pile.
C’est la methode emit
de SMTPHandler qui est responsable. Elle fait quoi cette méthode? Elle formate le “record”, crée un message et l’envoie à l’adresse mail spécifiée. Voilà le code:
def emit(self, record):
"""
Emit a record.
Format the record and send it to the specified addressees.
"""
try:
import smtplib
from email.utils import formatdate
port = self.mailport
if not port:
port = smtplib.SMTP_PORT
smtp = smtplib.SMTP(self.mailhost, port)
# C'est ici l'objet "record" est formatté
msg = self.format(record)
# Le message est construit ici. Il sera ensuite envoyé par smtp.sendmail
# C'est là que le bât blesse
msg = "From: %s\r\nTo: %s\r\nSubject: %s\r\nDate: %s\r\n\r\n%s" % (
self.fromaddr,
",".join(self.toaddrs),
# Notons ce getSubject(record). La méthode renvoie
# le sujet du message, passé à la création
# de mail_handler
self.getSubject(record),
formatdate(),
# le record formaté
msg)
if self.username:
if self.secure is not None:
smtp.ehlo()
smtp.starttls(*self.secure)
smtp.ehlo()
smtp.login(self.username, self.password)
# Le mail et envoyé
smtp.sendmail(self.fromaddr, self.toaddrs, msg)
smtp.quit()
except (KeyboardInterrupt, SystemExit):
raise
except:
self.handleError(record)
Qu’est-ce qu’il se passe?
Après quelques tests genre:
msg = self.format(record)
# C'est pratique parfois un petit print
print type(msg)
##
… on voit que la méthode format
(qui structure votre log selon la forme passée à logging.Formatter) retourne un objet de type unicode si le message que vous avez loggué (logger.critical(u"% foiré!", trace)
) contient de l’unicode.
Idem pour getSubject(record)
qui, en l’état, ne fait que retourner le sujet du email tel que vous l’avez passé à l’instanciation de SMTPHandler.
Donc, quand msg est formaté, si le log ou le message sont en unicode, msg sera en unicode.
J’ai été surpris quand j’ai fini par piger comment ça fonctionne. Même pour un débutant comme moi ça a l’air bête.
J’y connais rien en email, mais il ne m’a pas fallu longtemps pour comprendre que, dans sa forme basique, un email c’est du ascii, point. Et que si on veut envoyer autre chose que du ascii, qui soit décodable de l’autre côté, il faut qu’il y ait les headers appropriés, que le contenu soit encodé, que sais-je encore…
Peut-être un truc programmé par des gars qui ne manipulent jamais autre chose que de l’anglais? Ils auraient essayé d’envoyer un mail en russes ou en suédois, ça se serait planté au premier test. Oui, oui, Sam, la lingua franca, tout ça…
Ou alors c’est pour des questions de compatibilité avec des versions antérieures de python qui ne contiendraient pas les ressources nécessaires pour formater correctement un mail? Aucune idée…
Comment régler ça?
Le module email de la lib standard permet de créer des emails. On trouve dans email.mime
une classe MIMEText qui nous conviendra parfaitement. On va donc subclasser SMTPHandler et réécrire la méthode emit
pour qu’elle construise un message “RFC-compliant”, comme ils disent dans la doc.
class SMTPHandler_unicode(SMTPHandler):
def emit(self, record):
try:
import smtplib
from email.utils import formatdate
# On importe MIMEText
from email.mime.text import MIMEText
port = self.mailport
if not port:
port = smtplib.SMTP_PORT # 25
smtp = smtplib.SMTP(self.mailhost, port)
msg = self.format(record)
# Au moment de la création de l'objet par MIMEText,
# si msg est de type unicode, il sera encodé
# selon _charset, sinon il sera laissé tel quel
message = MIMEText(msg, _charset = "utf-8")
# On ajoute les headers nécessaires. S'il sont de type unicode,
# ils seront encodés selon _charset
message.add_header("Subject", self.getSubject(record))
message.add_header("From", self.fromaddr)
message.add_header("To", ",".join(self.toaddrs))
message.add_header("Date", formatdate())
if self.username:
if self.secure is not None:
smtp.ehlo()
smtp.starttls(*self.secure)
smtp.ehlo()
smtp.login(self.username, self.password)
# Envoi du message proprement encodé
smtp.sendmail(self.fromaddr, self.toaddrs, message.as_string())
smtp.quit()
except (KeyboardInterrupt, SystemExit):
raise
except:
self.handleError(record)
Ce qui est intéressant avec MIMEText c’est que si vous déclarez un encodage (_charset = "utf-8"
), et que vous passez une chaîne unicode a l’instanciation, il l’encodera selon _charset
.
Idem si vous ajoutez un header en appelant add_header
, ce qui permet dans notre cas de traiter correctement le sujet du mail.
L’appel à la méthode to_string
retournera le message proprement encodé (en base64) pour le transfert, et les headers appropriés seront inclus.
Voilà, il ne reste plus qu’à utiliser cette classe pour créer mail_handler, et le tour est joué.
mail_handler = SMTPHandler_unicode(
# host et port
('SMTP.GMAIL.COM', 587),
# From
"MOI@GMAIL.COM",
# To (liste)s
["QUELQU.UN@QUELQUE.PART"],
# sujet du message
u"Bonjour Mr Freud. %s a encore repéré des pensées génantes" % nom_loggeur,
# pour l'authentification
credentials = ("MONEMAIL@GMAIL.COM", "MONSUPERPASSWORD"),
secure = () )
Bilan de l’histoire: c’est en débutant qu’on devient débutant…