Profil de machine virtuelle Python

Aperçu

Je l'ai vu dans "Différence entre les boucles de niveau supérieur et les boucles dans les fonctions"

loop_toplevel.py

for i in range(10**7):
    pass

À titre d'exemple, profilons le traitement de la machine virtuelle Python et voyons que le traitement de STORE_NAME est efficace pour le temps d'exécution.

Vérifiez dans l'environnement Ubuntu 18.04.

Obtenir le code source Python

Obtenu sur https://github.com/python/cpython

~$ git clone https://github.com/python/cpython.git

Construire Python

Installez gcc

~$ sudo apt install -y gcc

Construire avec le profileur activé, l'optimisation désactivée

~$ cd cpython
~/cpython$ ./configure --enable-profiling --with-pydebug
~/cpython$ make

Profil

Préparez le script cible

~/cpython$ vi loop_toplevel.py
~/cpython$ cat loop_toplevel.py
for i in range(10**7):
    pass

Exécutez simplement le python construit et il vous profilera.

~/cpython$ ./python loop_toplevel.py

Le résultat du profil est enregistré dans gmon.out. Pour voir le résumé, faites simplement gprof. / Python.

~/cpython$ ls -l gmon.out
-rw-rw-r-- 1 vagrant vagrant 1284656 Nov  4 03:16 gmon.out
~/cpython$ gprof ./python|head -n 20
Flat profile:

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total
 time   seconds   seconds    calls   s/call   s/call  name
 17.46      0.22     0.22 20043118     0.00     0.00  read_size_t
  9.52      0.34     0.12     2229     0.00     0.00  _PyEval_EvalFrameDefault
  7.94      0.44     0.10 10007889     0.00     0.00  insertdict
  6.35      0.52     0.08 10026827     0.00     0.00  _PyMem_DebugRawAlloc
  6.35      0.60     0.08 10021559     0.00     0.00  _PyMem_DebugCheckAddress
  4.76      0.66     0.06 20045319     0.00     0.00  PyGILState_Check
  3.97      0.71     0.05 10020541     0.00     0.00  address_in_range
  3.97      0.76     0.05 10001148     0.00     0.00  PyLong_FromLong
  3.97      0.81     0.05 10046396     0.00     0.00  lookdict_unicode_nodummy
  3.97      0.86     0.05 10021024     0.00     0.00  _PyMem_DebugRawFree
  3.57      0.91     0.05 10019912     0.00     0.00  _PyObject_Free
  3.17      0.95     0.04 10027556     0.00     0.00  write_size_t
  3.17      0.99     0.04 10019415     0.00     0.00  _PyMem_DebugFree
  2.38      1.02     0.03 10017088     0.00     0.00  _PyDict_CheckConsistency
  2.38      1.05     0.03 10008245     0.00     0.00  PyDict_SetItem

Visualisez avec gprof2dot

Visualisons le graphe d'appel en utilisant gprof2dot.

~/cpython$ sudo apt install -y graphviz
~/cpython$ sudo apt install -y python3-pip
~/cpython$ pip3 install --user gprof2dot
~/cpython$ gprof ./python | ~/.local/bin/gprof2dot | dot -Tpng -o output.png

Nous avons constaté que PyDict_SetItem était appelé dans l'ordre du nombre de boucles et prenait moins de temps (temps total 51,14%, temps libre 2,31%, appels 10008245).

Vérifier la source

En regardant l'implémentation STORE_NAME de la VM Python, elle appelle PyDict_SetItem.

cpython/Python/ceval.c

case TARGET(STORE_NAME): {
    PyObject *name = GETITEM(names, oparg);
    PyObject *v = POP();
    PyObject *ns = f->f_locals;
    int err;
    if (ns == NULL) {
        _PyErr_Format(tstate, PyExc_SystemError,
                      "no locals found when storing %R", name);
        Py_DECREF(v);
        goto error;
    }
    if (PyDict_CheckExact(ns))
        err = PyDict_SetItem(ns, name, v);
    else
        err = PyObject_SetItem(ns, name, v);
    Py_DECREF(v);
    if (err != 0)
        goto error;
    DISPATCH();
}