{"id":1017,"date":"2014-12-16T16:48:52","date_gmt":"2014-12-16T14:48:52","guid":{"rendered":"http:\/\/saladtomatonion.com\/blog\/?p=1017"},"modified":"2016-08-08T11:28:38","modified_gmt":"2016-08-08T09:28:38","slug":"mesurer-le-temps-dexecution-de-code-en-python","status":"publish","type":"post","link":"https:\/\/saladtomatonion.com\/blog\/2014\/12\/16\/mesurer-le-temps-dexecution-de-code-en-python\/","title":{"rendered":"Mesurer le temps d’ex\u00e9cution de code en python"},"content":{"rendered":"

Aujourd’hui, on chronom\u00e8tre. J’imagine que, comme pour moi, c’est un besoin pour beaucoup que de savoir combien de temps tel ou tel bout de code prend \u00e0 se d\u00e9rouler. Je vous propose de voir comment j’ai fait.<\/p>\n

<\/p>\n

La m\u00e9thode na\u00efve<\/h3>\n

\u00c0 l’origine des temps, il y avait\u2026 time<\/code>, \u00e9videmment. Imaginons un appel serveur et un traitement sur les donn\u00e9es re\u00e7ues qu’on aimerait chronom\u00e9trer, par exemple. Le plus instinctif serait de faire comme suit:<\/p>\n

\r\nimport time\r\n\r\nstart_time = time.time()\r\ncontent = call_server(argument)\r\nresult = process_data(content)\r\ninterval = time.time() - start_time\r\nprint 'Total time in seconds:', interval\r\n<\/pre>\n
Mais proc\u00e9der comme ci-dessus signifie qu’il faut copier-coller le m\u00eame code \u00e0 tous les endroits o\u00f9 je souhaite faire des mesures. Si on factorisait tout \u00e7a?<\/p>\n
Moins de code = joli code<\/h3>\n
\u00c9crivons donc une classe qui va masquer<\/strong> les appels \u00e0 time.time()<\/code> et la soustraction.<\/p>\n
\r\nimport time\r\nclass Timer(object):\r\n    def start(self):\r\n        if hasattr(self, 'interval'):\r\n            del self.interval\r\n        self.start_time = time.time()\r\n\r\n    def stop(self):\r\n        if hasattr(self, 'start_time'):\r\n            self.interval = time.time() - self.start_time\r\n            del self.start_time # Force timer reinit\r\n\r\ntimer = Timer()\r\ntimer.start()\r\ncontent = call_server(argument)\r\nresult = process_data(content)\r\ntimer.stop()\r\nprint 'Total time in seconds for first call:', timer.interval\r\n\r\ntimer.start()\r\ncontent = call_server(argument_2)\r\nresult = process_data(content)\r\ntimer.stop()\r\nprint 'Total time in seconds for second call:', timer.interval\r\n<\/pre>\n
Il y a d\u00e9j\u00e0 un mieux! Je suis d\u00e9j\u00e0 s\u00fbr de ne pas me tromper entre mes copier-coller sur la fa\u00e7on de commencer et arr\u00eater mes mesures. Mais encore une fois, comme je n’aime pas me r\u00e9p\u00e9ter, je suis g\u00ean\u00e9 de devoir appeler \u00ab\u00a0\u00e0 la main\u00a0\u00bb les fonctions start()<\/code> et stop()<\/code>.<\/p>\n
Est-ce qu’il n’y aurait pas un moyen pour que ces appels soient faits automatiquement<\/strong> pour moi? Justement, il existe un design pattern en python appel\u00e9 \u00ab\u00a0context manager<\/strong><\/a>\u00ab\u00a0.<\/p>\n
Un contexte est une sorte d’isolation au runtime d’un morceau de code, utilisant le mot-cl\u00e9 with<\/code><\/strong>. Le context manager ex\u00e9cute automatiquement des instructions en entr\u00e9e et sortie du contexte. C’est exactement ce que je cherche!<\/p>\n
Une classe peut servir de context manager si elle impl\u00e9mente __enter__<\/code> et __exit__<\/code>.<\/p>\n
Ma classe devient donc la suivante:<\/p>\n
\r\nclass Timer(object):\r\n    def __enter__(self):\r\n        self.start()\r\n        # __enter__ must return an instance bound with the \"as\" keyword\r\n        return self\r\n    \r\n    # There are other arguments to __exit__ but we don't care here\r\n    def __exit__(self, *args, **kwargs): \r\n        self.stop()\r\n    \r\n    def start(self):\r\n        if hasattr(self, 'interval'):\r\n            del self.interval\r\n        self.start_time = time.time()\r\n\r\n    def stop(self):\r\n        if hasattr(self, 'start_time'):\r\n            self.interval = time.time() - self.start_time\r\n            del self.start_time # Force timer reinit\r\n\r\nwith Timer() as timer:\r\n    content = call_server()\r\n    result = process_data(content)\r\nprint 'Total time in seconds for first call:', timer.interval\r\n<\/pre>\n
De mieux en mieux!<\/p>\n
Maintenant, j’aimerais aussi me passer d’\u00e9crire le print<\/code> final! Je pourrais tr\u00e8s bien ajouter un print dans la fonction stop<\/code>, ou encore dans la fonction __exit__<\/code>. Mais j’ai envie d’\u00eatre plus malin, pour pr\u00e9voir d’envoyer ma donn\u00e9e vers une fonction de \u00ab\u00a0log\u00a0\u00bb quelconque<\/strong>.<\/p>\n
Je vais donc construire une classe d\u00e9riv\u00e9e<\/strong> qui prendra en param\u00e8tre une fonction ainsi qu’un message afin de mieux qualifier ce que je vais \u00e9crire. Pour rendre \u00e7a plus facile au quotidien, je pr\u00e9vois aussi une valeur par d\u00e9faut pour la fonction \u00e0 appeler.<\/p>\n
\r\nclass LoggerTimer(Timer):\r\n    @staticmethod\r\n    def default_logger(msg):\r\n        print msg\r\n\r\n    def __init__(self, prefix='', func=None):\r\n        # Use func if not None else the default one\r\n        self.f = func or LoggerTimer.default_logger\r\n        # Format the prefix if not None or empty, else use empty string\r\n        self.prefix = '{0}:'.format(prefix) if prefix else ''\r\n\r\n    def stop(self):\r\n        # Call the parent method\r\n        super(LoggerTimer, self).stop()\r\n        # Call the logging function with the message\r\n        self.f('{0}{1}'.format(self.prefix, self.interval))\r\n<\/pre>\n
Ainsi, je peux utiliser mon nouveau timer comme suit:<\/p>\n
\r\n# With default print function\r\nwith LoggerTimer('Server call and processing'):\r\n    content = call_server()\r\n    result = process_data(content)\r\n\r\n# With custom logging function\r\nimport logging\r\nlogger = logging.getLogger('loggertimer.test')\r\nwith LoggerTimer('Server call and processing', logger.debug):\r\n    content = call_server()\r\n    result = process_data(content)\r\n<\/pre>\n
Une corde de plus \u00e0 cet arc?<\/h3>\n
Il me vient soudain une id\u00e9e saugrenue. Et si je souhaitais chronom\u00e9trer une certaine fonction \u00e0 chaque appel, sans avoir besoin d’ins\u00e9rer le code de LoggerTimer<\/code> dans le corps de la fonction?<\/p>\n
J’aimerais pouvoir utiliser un d\u00e9corateur<\/strong> pour avoir \u00e7a:<\/p>\n
\r\n@LoggerTimer('The function', logger.debug)\r\ndef the_function(argument):\r\n    content = server_call(argument)\r\n    return process_data(content)\r\n<\/pre>\n
Je ne reviens pas en d\u00e9tail sur le principe de d\u00e9corateur. Je rappellerai simplement qu’un d\u00e9corateur est une fonction qui prend pour param\u00e8tre la fonction \u00e0 d\u00e9corer, et qui renvoie cette m\u00eame fonction ou une version modifi\u00e9e (dite d\u00e9cor\u00e9e).<\/p>\n
Mais mon instance de LoggerTimer est un objet, et pas une fonction! Pour simuler la capacit\u00e9 d’\u00eatre \u00ab\u00a0appel\u00e9\u00a0\u00bb, je lui impl\u00e9mente la m\u00e9thode __call__<\/code><\/p>\n
Ma classe devient donc:<\/p>\n
\r\nclass LoggerTimer(Timer):\r\n    @staticmethod\r\n    def default_logger(msg):\r\n        print msg\r\n\r\n    def __init__(self, prefix='', func=None)\r\n        # Use func if not None else the default one\r\n        self.f = func or LoggerTimer.default_logger\r\n        # Format the prefix if not None or empty, else use empty string\r\n        self.prefix = '{0}:'.format(prefix) if prefix else ''\r\n\r\n    def stop(self):\r\n        # Call the parent method\r\n        super(LoggerTimer, self).stop()\r\n        # Call the logging function with the message\r\n        self.f('{0}{1}'.format(self.prefix, self.interval))\r\n\r\n    def __call__(self, func):\r\n        # Use self as context manager in a decorated function\r\n        def decorated_func(*args, **kwargs):\r\n            with self: return func(*args, **kwargs)\r\n        return decorated_func\r\n<\/pre>\n
Et voil\u00e0 une belle classe utilitaire qui peut servir dans de nombreux cas. Si vous avez d’autres id\u00e9es de ce qu’on pourrait tirer de ce principe, avec d’autres d\u00e9rivations possibles, n’h\u00e9sitez pas \u00e0 les soumettre ci-dessous!<\/p>\n","protected":false},"excerpt":{"rendered":"
Aujourd’hui, on chronom\u00e8tre. J’imagine que, comme pour moi, c’est un besoin pour beaucoup que de savoir combien de temps tel ou tel bout de code prend \u00e0 se d\u00e9rouler. Je vous propose de voir...<\/p>\n","protected":false},"author":2,"featured_media":708,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"footnotes":"","jetpack_publicize_message":"","jetpack_is_tweetstorm":false,"jetpack_publicize_feature_enabled":true,"jetpack_social_post_already_shared":false,"jetpack_social_options":{"image_generator_settings":{"template":"highway","enabled":false}}},"categories":[4],"tags":[251,250,249,244,245,248,21,254,38,247,246,252,253],"jetpack_publicize_connections":[],"jetpack_featured_media_url":"https:\/\/saladtomatonion.com\/blog\/wp-content\/uploads\/2011\/04\/python-logo-glassy-small.png","jetpack_sharing_enabled":true,"_links":{"self":[{"href":"https:\/\/saladtomatonion.com\/blog\/wp-json\/wp\/v2\/posts\/1017"}],"collection":[{"href":"https:\/\/saladtomatonion.com\/blog\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/saladtomatonion.com\/blog\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/saladtomatonion.com\/blog\/wp-json\/wp\/v2\/users\/2"}],"replies":[{"embeddable":true,"href":"https:\/\/saladtomatonion.com\/blog\/wp-json\/wp\/v2\/comments?post=1017"}],"version-history":[{"count":42,"href":"https:\/\/saladtomatonion.com\/blog\/wp-json\/wp\/v2\/posts\/1017\/revisions"}],"predecessor-version":[{"id":1213,"href":"https:\/\/saladtomatonion.com\/blog\/wp-json\/wp\/v2\/posts\/1017\/revisions\/1213"}],"wp:featuredmedia":[{"embeddable":true,"href":"https:\/\/saladtomatonion.com\/blog\/wp-json\/wp\/v2\/media\/708"}],"wp:attachment":[{"href":"https:\/\/saladtomatonion.com\/blog\/wp-json\/wp\/v2\/media?parent=1017"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/saladtomatonion.com\/blog\/wp-json\/wp\/v2\/categories?post=1017"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/saladtomatonion.com\/blog\/wp-json\/wp\/v2\/tags?post=1017"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}