Completion profiling¶

Links: notebook, html, PDF, python, slides, GitHub

Profiling avec cProfile, memory_profiler, pyinstrument, snakeviz.

line_profiler ne semble pas plus être maintenu.

%matplotlib inline
import matplotlib.pyplot as plt
plt.style.use('ggplot')
from jyquickhelper import add_notebook_menu
add_notebook_menu()

Setup
- Function to profile
- Data
Standard modules
- cProfile
Others informations when profiling
- memory_profiler
Static Visualization
- gprof2dot
- pyinstrument
Javascript Visualization
- SnakeViz
- vprof

Setup ¶

Function to profile ¶

from mlstatpy.nlp.completion import CompletionTrieNode

def gain_dynamique_moyen_par_mot(queries, weights):
    per = list(zip(weights, queries))
    total = sum(weights) * 1.0
    res = []
    trie = CompletionTrieNode.build([(None, q) for _, q in per])
    trie.precompute_stat()
    trie.update_stat_dynamic()
    wks = [(w, p, len(w) - trie.min_keystroke0(w)[0]) for p, w in per]
    wks_dyn = [(w, p, len(w) - trie.min_dynamic_keystroke(w)[0])
               for p, w in per]
    wks_dyn2 = [(w, p, len(w) - trie.min_dynamic_keystroke2(w)[0])
                for p, w in per]
    gain = sum(g * p / total for w, p, g in wks)
    gain_dyn = sum(g * p / total for w, p, g in wks_dyn)
    gain_dyn2 = sum(g * p / total for w, p, g in wks_dyn2)
    ave_length = sum(len(w) * p / total for p, w in per)
    return gain, gain_dyn, gain_dyn2, ave_length

Data ¶

from mlstatpy.data.wikipedia import download_titles
file_titles = download_titles(country='fr')

len(file_titles)

from mlstatpy.data.wikipedia import enumerate_titles
list_titles = list(sorted(set(_ for _ in enumerate_titles(file_titles) if 'A' <= _[0] <= 'Z')))

import random
sample1000 = random.sample(list_titles, 1000)
with open("sample1000.txt", "w", encoding="utf-8") as f:
    f.write("\n".join(sample1000))

Standard modules ¶

cProfile ¶

import cProfile, io, pstats, os

def toprofile0(lines):
    gain_dynamique_moyen_par_mot(lines, [1.0] * len(lines))

def doprofile(lines, filename):
    pr = cProfile.Profile()
    pr.enable()
    toprofile0(lines)
    pr.disable()
    s = io.StringIO()
    ps = pstats.Stats(pr, stream=s).sort_stats('cumulative')
    ps.print_stats()
    rem = os.path.normpath(os.path.join(os.getcwd(), "..", "..", ".."))
    res = s.getvalue().replace(rem, "")
    ps.dump_stats(filename)
    return res

r = doprofile(sample1000, "completion.prof")
print(r)

      1524620 function calls in 2.027 seconds
Ordered by: cumulative time
ncalls  tottime  percall  cumtime  percall filename:lineno(function)
     1    0.000    0.000    2.027    2.027 <ipython-input-8-d2b6d910fdd7>:3(toprofile0)
     1    0.055    0.055    2.027    2.027 <ipython-input-3-684f3e860cf5>:3(gain_dynamique_moyen_par_mot)
     1    0.234    0.234    1.246    1.246 srcmlstatpynlpcompletion.py:415(precompute_stat)
 16158    0.244    0.000    0.790    0.000 srcmlstatpynlpcompletion.py:503(merge_completions)
     1    0.121    0.121    0.490    0.490 srcmlstatpynlpcompletion.py:450(update_stat_dynamic)
 16158    0.317    0.000    0.324    0.000 {built-in method builtins.__build_class__}
 34312    0.144    0.000    0.259    0.000 srcmlstatpynlpcompletion.py:555(update_dynamic_minimum_keystroke)
     1    0.190    0.190    0.213    0.213 srcmlstatpynlpcompletion.py:203(build)
 36173    0.108    0.000    0.124    0.000 srcmlstatpynlpcompletion.py:523(<listcomp>)
 34312    0.083    0.000    0.094    0.000 srcmlstatpynlpcompletion.py:588(second_step)
 16159    0.007    0.000    0.060    0.000 {method 'extend' of 'collections.deque' objects}
 36464    0.032    0.000    0.059    0.000 {built-in method builtins.all}
349348    0.056    0.000    0.056    0.000 {built-in method builtins.len}
  1001    0.035    0.000    0.054    0.000 srcmlstatpynlpcompletion.py:132(leaves)
 16158    0.042    0.000    0.050    0.000 srcmlstatpynlpcompletion.py:542(update_minimum_keystroke)
 17157    0.026    0.000    0.039    0.000 srcmlstatpynlpcompletion.py:97(unsorted_iter)
 17156    0.033    0.000    0.036    0.000 srcmlstatpynlpcompletion.py:624(init_dynamic_minimum_keystroke)
 16158    0.028    0.000    0.036    0.000 {built-in method builtins.sorted}
179563    0.035    0.000    0.035    0.000 {built-in method builtins.hasattr}
106678    0.032    0.000    0.032    0.000 srcmlstatpynlpcompletion.py:435(<genexpr>)
133412    0.026    0.000    0.026    0.000 {method 'values' of 'dict' objects}
 64632    0.021    0.000    0.021    0.000 {method 'extend' of 'list' objects}
 52333    0.020    0.000    0.020    0.000 {method 'append' of 'list' objects}
 68624    0.016    0.000    0.016    0.000 {method 'pop' of 'list' objects}
 17156    0.014    0.000    0.015    0.000 srcmlstatpynlpcompletion.py:20(__init__)
 22980    0.015    0.000    0.015    0.000 {built-in method builtins.min}
  3000    0.014    0.000    0.014    0.000 srcmlstatpynlpcompletion.py:257(find)
 20015    0.013    0.000    0.013    0.000 {built-in method builtins.max}
 55616    0.011    0.000    0.011    0.000 {method 'popleft' of 'collections.deque' objects}
 64632    0.009    0.000    0.009    0.000 {method 'items' of 'dict' objects}
 17158    0.008    0.000    0.008    0.000 srcmlstatpynlpcompletion.py:517(<genexpr>)
 37461    0.008    0.000    0.008    0.000 {method 'append' of 'collections.deque' objects}
     1    0.001    0.001    0.008    0.008 <ipython-input-3-684f3e860cf5>:10(<listcomp>)
 16158    0.007    0.000    0.007    0.000 srcmlstatpynlpcompletion.py:511(<listcomp>)
 16158    0.007    0.000    0.007    0.000 srcmlstatpynlpcompletion.py:508(Fake)
     1    0.001    0.001    0.007    0.007 <ipython-input-3-684f3e860cf5>:11(<listcomp>)
     1    0.001    0.001    0.007    0.007 <ipython-input-3-684f3e860cf5>:13(<listcomp>)
 17155    0.007    0.000    0.007    0.000 srcmlstatpynlpcompletion.py:54(_add)
  1000    0.001    0.000    0.007    0.000 srcmlstatpynlpcompletion.py:321(min_keystroke0)
  1000    0.001    0.000    0.006    0.000 srcmlstatpynlpcompletion.py:352(min_dynamic_keystroke)
  1000    0.001    0.000    0.006    0.000 srcmlstatpynlpcompletion.py:382(min_dynamic_keystroke2)
 18156    0.002    0.000    0.002    0.000 {built-in method builtins.isinstance}
     5    0.001    0.000    0.002    0.000 {built-in method builtins.sum}
  1001    0.000    0.000    0.000    0.000 <ipython-input-3-684f3e860cf5>:18(<genexpr>)
     1    0.000    0.000    0.000    0.000 <ipython-input-3-684f3e860cf5>:7(<listcomp>)
  1001    0.000    0.000    0.000    0.000 <ipython-input-3-684f3e860cf5>:16(<genexpr>)
  1001    0.000    0.000    0.000    0.000 <ipython-input-3-684f3e860cf5>:17(<genexpr>)
  1001    0.000    0.000    0.000    0.000 <ipython-input-3-684f3e860cf5>:15(<genexpr>)
     1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

Others informations when profiling ¶

memory_profiler ¶

See memory_profiler.

from memory_profiler import profile
%load_ext memory_profiler

%memit toprofile0(sample1000)

peak memory: 418.86 MiB, increment: 17.05 MiB

from io import StringIO
st = StringIO()
@profile(stream=st)
def toprofile(lines):
    gain_dynamique_moyen_par_mot(lines, [1.0] * len(lines))
toprofile(sample1000)

ERROR: Could not find file <ipython-input-12-7512ff5cdee3>
NOTE: %mprun can only be used on functions defined in physical files, and not in the IPython environment.

%%file temp_mem_profile.py

from mlstatpy.nlp.completion import CompletionTrieNode
from memory_profiler import profile

@profile(precision=4)
def gain_dynamique_moyen_par_mot(queries, weights):
    per = list(zip(weights, queries))
    total = sum(weights) * 1.0
    res = []
    trie = CompletionTrieNode.build([(None, q) for _, q in per])
    trie.precompute_stat()
    trie.update_stat_dynamic()
    wks = [(w, p, len(w) - trie.min_keystroke0(w)[0]) for p, w in per]
    wks_dyn = [(w, p, len(w) - trie.min_dynamic_keystroke(w)[0])
               for p, w in per]
    wks_dyn2 = [(w, p, len(w) - trie.min_dynamic_keystroke2(w)[0])
                for p, w in per]
    gain = sum(g * p / total for w, p, g in wks)
    gain_dyn = sum(g * p / total for w, p, g in wks_dyn)
    gain_dyn2 = sum(g * p / total for w, p, g in wks_dyn2)
    ave_length = sum(len(w) * p / total for p, w in per)
    return gain, gain_dyn, gain_dyn2, ave_length

@profile(precision=4)
def toprofile():
    with open("sample1000.txt", "r", encoding="utf-8") as f:
        lines = [_.strip("\n\r ") for _ in f.readlines()]
    gain_dynamique_moyen_par_mot(lines, [1.0] * len(lines))
toprofile()

Overwriting temp_mem_profile.py

import sys
cmd = sys.executable
from pyquickhelper.loghelper import run_cmd
cmd += " -m memory_profiler temp_mem_profile.py"
out, err = run_cmd(cmd, wait=True)
print(out)

Filename: temp_mem_profile.py
Line #    Mem usage    Increment   Line Contents
================================================
     5  65.0938 MiB  65.0938 MiB   @profile(precision=4)
     6                             def gain_dynamique_moyen_par_mot(queries, weights):
     7  65.0938 MiB   0.0000 MiB       per = list(zip(weights, queries))
     8  65.0938 MiB   0.0000 MiB       total = sum(weights) * 1.0
     9  65.0938 MiB   0.0000 MiB       res = []
    10  71.7266 MiB   6.6172 MiB       trie = CompletionTrieNode.build([(None, q) for _, q in per])
    11  79.5000 MiB   7.7734 MiB       trie.precompute_stat()
    12  89.2930 MiB   9.7930 MiB       trie.update_stat_dynamic()
    13  89.2930 MiB   0.0000 MiB       wks = [(w, p, len(w) - trie.min_keystroke0(w)[0]) for p, w in per]
    14  89.2930 MiB   0.0000 MiB       wks_dyn = [(w, p, len(w) - trie.min_dynamic_keystroke(w)[0])
    15  89.2930 MiB   0.0000 MiB                  for p, w in per]
    16  89.2930 MiB   0.0000 MiB       wks_dyn2 = [(w, p, len(w) - trie.min_dynamic_keystroke2(w)[0])
    17  89.2930 MiB   0.0000 MiB                   for p, w in per]
    18  89.2930 MiB   0.0000 MiB       gain = sum(g * p / total for w, p, g in wks)
    19  89.2930 MiB   0.0000 MiB       gain_dyn = sum(g * p / total for w, p, g in wks_dyn)
    20  89.2930 MiB   0.0000 MiB       gain_dyn2 = sum(g * p / total for w, p, g in wks_dyn2)
    21  89.2930 MiB   0.0000 MiB       ave_length = sum(len(w) * p / total for p, w in per)
    22  89.2930 MiB   0.0000 MiB       return gain, gain_dyn, gain_dyn2, ave_length

Filename: temp_mem_profile.py
Line #    Mem usage    Increment   Line Contents
================================================
    24  64.9609 MiB  64.9609 MiB   @profile(precision=4)
    25                             def toprofile():
    26  64.9609 MiB   0.0000 MiB       with open("sample1000.txt", "r", encoding="utf-8") as f:
    27  65.0938 MiB   0.0625 MiB           lines = [_.strip("nr ") for _ in f.readlines()]
    28  89.2930 MiB  24.1992 MiB       gain_dynamique_moyen_par_mot(lines, [1.0] * len(lines))

Static Visualization ¶

gprof2dot ¶

See gprof2dot.

import gprof2dot
import sys
sys.argv=["", "-f", "pstats", "completion.prof", "-o", "completion.dot"]
gprof2dot.main()

from pyquickhelper.helpgen.conf_path_tools import find_graphviz_dot
dot = find_graphviz_dot()

from pyquickhelper.loghelper import run_cmd
out, err = run_cmd('"{0}" completion.dot -Tpng -ocompletion.png'.format(dot), wait=True)
print(out)

from pyquickhelper.helpgen import NbImage
name = "completion.png"
if os.path.exists("images/completion.jpg"):
    # replacing by jpg because latex conversion does not like png with transparency
    name = "images/completion.jpg"
NbImage(name, width=800)

../_images/completion_profiling_26_0.jpeg

pyinstrument ¶

See pyinstrument.

from pyinstrument import Profiler

profiler = Profiler(use_signal=False)
profiler.start()

toprofile0(sample1000)

profiler.stop()
out = profiler.output_text(unicode=False, color=False)
print(out.replace("\\", "/"))

  _     ._   __/__   _ _  _  _ _/_   Recorded: 23:07:05  Samples:  913
 /_//_/// /_/ / //_// / //_'/ //     Duration: 1.668     CPU time: 1.641
/   _/                      v3.0.1
Program:  -f pstats completion.prof -o completion.dot
1.667 run_code  IPython/core/interactiveshell.py:3259
`- 1.667 <module>  <ipython-input-19-f16978ea99ef>:6
   `- 1.667 toprofile0  <ipython-input-8-d2b6d910fdd7>:3
      `- 1.667 gain_dynamique_moyen_par_mot  <ipython-input-3-684f3e860cf5>:3
         |- 0.896 precompute_stat  mlstatpy/nlp/completion.py:415
         |  |- 0.652 merge_completions  mlstatpy/nlp/completion.py:503
         |  |  |- 0.558 [self]
         |  |  `- 0.086 <listcomp>  mlstatpy/nlp/completion.py:523
         |  |- 0.159 [self]
         |  |- 0.041 leaves  mlstatpy/nlp/completion.py:132
         |  `- 0.035 update_minimum_keystroke  mlstatpy/nlp/completion.py:542
         |- 0.371 build  mlstatpy/nlp/completion.py:203
         |  |- 0.343 [self]
         |  `- 0.021 __init__  mlstatpy/nlp/completion.py:20
         `- 0.370 update_stat_dynamic  mlstatpy/nlp/completion.py:450
            |- 0.247 update_dynamic_minimum_keystroke  mlstatpy/nlp/completion.py:555
            |  |- 0.159 [self]
            |  `- 0.088 second_step  mlstatpy/nlp/completion.py:588
            |- 0.066 [self]
            |- 0.037 init_dynamic_minimum_keystroke  mlstatpy/nlp/completion.py:624
            `- 0.019 unsorted_iter  mlstatpy/nlp/completion.py:97

Javascript Visualization ¶

SnakeViz ¶

%load_ext snakeviz

L’instruction qui suit lance l’explorateur par défaut avec les données du profilage.

# %snakeviz toprofile0(sample1000)

from pyquickhelper.helpgen import NbImage
NbImage("images/func_info.jpg", width=400)

../_images/completion_profiling_34_0.jpeg

vprof ¶

See vprof.

from vprof import profiler

# needs to be run from a file not from a notebook
# profiler.run(toprofile0, 'cmh', args=(sample1000,), host='localhost', port=8000)

from pyquickhelper.helpgen import NbImage
NbImage("images/vprof.jpg", width=800)

../_images/completion_profiling_37_0.jpeg

Liens

Contenu

Information

Completion profiling¶

Setup ¶

Function to profile ¶

Data ¶

Standard modules ¶

cProfile ¶

Others informations when profiling ¶

memory_profiler ¶

Static Visualization ¶

gprof2dot ¶

pyinstrument ¶

Javascript Visualization ¶

SnakeViz ¶

vprof ¶