Qui est le plus fort entre l'éléphant et l'hippopotame

hr — Wed, 02 Apr 2008 15:31:00 +0200

Je me pose toujours des questions de performance lorsque je développe. Il y a souvent plusieurs façons de rêgler un problème et certaines plus consommatrices de ressources que d'autres. Dans le cas qui m'intéresse, je me questionne sur la performance des expressions régulières en regard d'autres méthodes de traitement de chaîne. Je dois effectuer un traitement sur un très grand nombre de lignes de log au fur et à mesure de leur émission en syslog.

La plupart du temps avec python, avoir une idée innovante est modérée par l'existence d'un module qui couvre déjà le sujet. Dans ce cas, le module timeit va me permettre de tester la rapidité d'exécution de différents bouts de code.

Le format d'une ligne de log syslog est connu et décrit par la RFC3164, ce format me permet différentes approches pour en extraire différents champs. Dans mon cas, je vais extraire le champ appelé HEADER de différentes façons. Un ligne de log syslog doit être de la forme :

<     >TIMESTAMP HOSTNAME TAG CONTENT
| PRI |      HEADER      |    MSG

Dans le code python ci-dessous, les trois fonctions testées sont :

split() qui récupère le champ header en effectuant un split sur le caractère espace et en réunissant les champs résultants.
match() effectue une sélection par expression régulière.
match_full() effectue une capture par expression régulière et occurence nommée.

Il est important de bien faire attention au contexte et à la portée des variables et fonctions ("scope" et "namespace") lorsqu'on utilise timeit.

import timeit

def split():
    str = '<22>Mar 27 16:13:35 192.168.1.1 mx-daemon[2754]: m2RFDTbw002754: from=<j.doe@nowhere.com>, size=3356, class=0, nrcpts=1, msgid=<000701c8902d$04cb7356$879fa6b4@epwlhnj>, proto=ESMTP, daemon=MX, relay=[192.168.1.2]'
    ' '.join(str.split()[0:4]).split('>')[1]

def match():
    import re
    pattern = r'^<(\d+)>(\w{3} (?: |\d)\d \d\d:\d\d:\d\d [\w:.]+) (\w+.+)'
    _pattern = re.compile(pattern)
    str = '<22>Mar 27 16:13:35 192.168.1.1 mx-daemon[2754]: m2RFDTbw002754: from=<j.doe@nowhere.com>, size=3356, class=0, nrcpts=1, msgid=<000701c8902d$04cb7356$879fa6b4@epwlhnj>, proto=ESMTP, daemon=MX, relay=[192.168.1.2]'
    _pattern.search(str).group(2)

def match_full():
    import re
    pattern_full = r'^<(?P<pri>\d+)>(?P<header>\w{3} (?: |\d)\d \d\d:\d\d:\d\d [\w:.]+) (?P<msg>\w+.+)'
    _pattern_full = re.compile(pattern_full)
    str = '<22>Mar 27 16:13:35 192.168.1.1 mx-daemon[2754]: m2RFDTbw002754: from=<j.doe@nowhere.com>, size=3356, class=0, nrcpts=1, msgid=<000701c8902d$04cb7356$879fa6b4@epwlhnj>, proto=ESMTP, daemon=MX, relay=[192.168.1.2]'
    _pattern_full.search(str).groupdict()['header']

print "split:"
print timeit.Timer("split()", "from __main__ import split").timeit()
print "match:"
print timeit.Timer("match()", "from __main__ import match").timeit()
print "match_full:"
print timeit.Timer("match_full()", "from __main__ import match_full").timeit()

Ce qui donne après exécution :

$ python stress.py
split:
6.14724898338
match:
14.80702281
match_full:
19.0696430206

En y réfléchissant bien, les fonctions testées ne sont pas vraiment optimisées et ne sont pas donc comparables en vitesse d'exécution. Pour vraiment jouer sur un pied d'égalité, je procède aux modifications suivantes :

Import du module re en début de script, ça fonctionne finalement, j'avais peur que les problèmes de contexte de timeit ne posent problème.
La compilation des expressions régulières est faite une fois pour toute et pas à chaque lancement des fonctions cmatch() et cmatch_full()
Introduction de deux nouvelles fonctions effectuant une capture par expression régulière sans compilation de l'expression.
Utilisation de la méthode repeat() plutôt que timeit() pour essayer d'obtenir un résultat moins influencé par le fonctionnement du système.

import re, timeit

str='<22>Mar 27 16:13:35 192.168.1.1 mx-daemon[2754]: m2RFDTbw002754: from=<j.doe@nowhere.com>, size=3356, class=0, nrcpts=1, msgid=<000701c8902d$04cb7356$879fa6b4@epwlhnj>, proto=ESMTP, daemon=MX, relay=[192.168.1.2]'

split_init = """from __main__ import split"""
match_init = """from __main__ import match"""
match_full_init = """from __main__ import match_full"""
cmatch_init = """from __main__ import cmatch"""
cmatch_full_init = """from __main__ import cmatch_full"""

pattern = r'^<(\d+)>(\w{3} (?: |\d)\d \d\d:\d\d:\d\d [\w:.]+) (\w+.+)'
pattern_full = r'^<(?P<pri>\d+)>(?P<header>\w{3} (?: |\d)\d \d\d:\d\d:\d\d [\w:.]+) (?P<msg>\w+.+)'
_pattern = re.compile(pattern)
_pattern_full = re.compile(pattern_full)

def split():
    ' '.join(str.split(' ')[0:4]).split('>')[1]

def match():
    re.search(pattern, str).group(2)

def match_full():
    re.search(pattern_full, str).groupdict()['header']

def cmatch():
    _pattern.search(str).group(2)

def cmatch_full():
    _pattern_full.search(str).groupdict()['header']

print "Testing %d occurences of each match, %d times" % (timeit.default_number, timeit.default_repeat)
split_result = timeit.Timer("split()", split_init).repeat()
print "split: %fs %s" % (min(split_result), split_result)
match_result = timeit.Timer("match()", match_init).repeat()
print "match: %fs %s" % (min(match_result), match_result)
match_full_result = timeit.Timer("match_full()", match_full_init).repeat()
print "match_full: %fs %s" % (min(match_full_result), match_full_result)
cmatch_result = timeit.Timer("cmatch()", cmatch_init).repeat()
print "cmatch: %fs %s" % (min(cmatch_result), cmatch_result)
cmatch_full_result = timeit.Timer("cmatch_full()", cmatch_full_init).repeat()
print "cmatch_full: %fs %s" % (min(cmatch_full_result), cmatch_full_result)

Qui me donne les résultats suivants :

$ python stress.py
Testing 1000000 occurences of each match, 3 times
split: 5.818318s [5.8183181285858154, 6.5981872081756592, 6.327794075012207]
match: 8.220056s [8.2262570858001709, 8.2361149787902832, 8.2200560569763184]
match_full: 12.399510s [12.40582799911499, 12.399509906768799, 12.501888036727905]
cmatch: 3.818037s [3.8180370330810547, 3.8276369571685791, 3.8310809135437012]
cmatch_full: 6.724747s [6.7247469425201416, 6.7392361164093018, 6.7564170360565186]

Il est surprenant de constater la différence énorme entre les expressions régulières compilées et non compilées, l'avantage de compiler ses expressions dans le cas d'une utilisation de masse est évident. La rapidité de split() est plutôt décevante par rapport à l'utilisation des expressions régullières.

Ces tests sont intéressant et donnent des indications de performance mais ne remplacent pas des tests complet de profilage.

ZenTech - timeit

Qui est le plus fort entre l'éléphant et l'hippopotame