Mélangeons les deux !

import sys
import traceback
import pdb

def pdb_post_mortem(exc_type, exc_val, exc_tb):
    # On affiche l'exception histoire de savoir ce qu'on debug
    print("".join(traceback.format_exception(exc_type, exc_val, exc_tb)))
    # On balance pdb en mode post mortem, c'est à dire qu'il va se lancer
    # malgré le fait que le programme ne marche plus, donnant accès
    # au contexte qu'il y avait juste avant que ça foire
    pdb.post_mortem(exc_tb)

# On dit à python de lancer cette fonction quand il plante
sys.excepthook = pdb_post_mortem

# On fait planter Python histoire de voir que ça marche bien

def boom():
    a = 1
    b = a / 0
boom()

Et si quand ça plante, Python nous pond la stack trace, puis nous lance un joli prompt de debugging qui donne accès à ce qu’on avait en mémoire just avant que la VM ne décède :

Traceback (most recent call last):
  File "test.py", line 16, in 
    boom()
  File "test.py", line 14, in boom
    b = a / 0
ZeroDivisionError: integer division or modulo by zero

> /home/sam/Bureau/test.py(14)test()
-> a = 1 / 0
(Pdb) 1
(Pdb) print a
1

C’est plus ou moins l’équivalent de lancer son programme manuellement avec :

python -m pdb programme.py

L’avantage de la première forme, c’est qu’on peut le setter et l’oublier, on faire une config un peu plus custom. L’avantage de la deuxième forme, c’est que c’est juste une ligne à taper, et en prime si on fait c, le programme redémarre automatiquement.

Les exceptions suivantes sont levées en cas d’erreur. Elles héritent toutes de StandardError :

Je n’ai pas mentionné quelques exceptions beaucoup plus rares, mais vous pouvez trouver la liste complète ici.

Toutes les exceptions héritent de BaseException, y compris Exception.

Il existe 3 exceptions qui n’héritent pas de Exception, et ne représentent PAS des erreurs :

• SystemExit : levé par sys.exit() qui par nature met fin au programme. N’affiche pas de stack trace quand la VM s’arrête si elle n’est pas attrapée.
• KeyboardInterrupt : levé par des combinaison de touches au clavier qui par nature mettent fin au programme (comme Ctrl + C).
• GeneratorExit : levé automatiquement quand on appelle close() sur un générateur.

Bien qu’héritant d’Exception, les warnings sont des mécanismes un peu particulier. Ils sont tous notés XxxWarning (ex: DeprecationWarning pour signaler l’usage d’une fonctionnalité en cours de dépréciation) et sont des enfants de Warning.

Généralement les warnings ne sont pas fait pour être levés avec raise, mais appelé avec warnings.warn. Par défaut ces warnings sont affichés, mais peuvent être réduits au silence, filtrés ou levés comme exception selon le désir du développeur.

Enfin, StopIteration est levée quand on appelle next() sur un itérateur vide. C’est le seul enfant de Exception (avec Warning) qui n’hérite pas de StandardError car ce n’est pas une erreur en soit, mais simplement un mécanisme de contrôle de flux qui dit à la boucle for quand s’arrêter.

>>> for x in Exception('Doh !'):
...     print x
...
Doh !

Pourquoi ? J’en ai aucune idée. Mais j’ai voulu faire un algo récursif sur des structures imbriquées contenant des exceptions. Et ça buggait. Parce que ça parcourait aussi les exceptions.

Le piège vicieux dans lequel peu de gens risquent de tomber vu qu’on programme pas ça tous les jours. Mais tout de même, une étrangetée de Python. Peut être un héritage de l’époque où on pouvait faire un raise sur une string.

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.

Log post mortem par email

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…

SMTPHandler ne gère pas unicode

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.

Toi, là au fond! Oui, toi!

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.

WTF!?

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?

Il mangea u”\xe9″ et il en redemanda

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…

Par exemple:

class Truc(threading.Condition):
    pass

class Machine(tempfile.NamedTemporaryFile):
    pass

Lèveront l’exception :

TypeError: Error when calling the metaclass bases 
    function() argument 1 must be code, not str

Car:

>>> import threading, tempfile
>>> type(threading.Condition)

>>> type(tempfile.NamedTemporaryFile)

Malgré leurs noms en majuscule.

Le message d’erreur est lui-même complètement obscure. Bref, le genre de truc qui est 100% lié à des erreurs d’autres personnes que vous aller payer par une après-midi de debug si on ne vous donne pas la solution.

Mais bon, la queue de celui qui n’a jamais pourri l’après-midi d’un autre codeur avec son travail merdique jette le premier parpaing.