Acabo de subir la primera versión de mi nuevo pequeño proyecto: ¡un perfilador de OpenObject para OpenERP!

Por si te estás preguntando qué es un perfilador, encontré esta bonita definición: "Un perfilador es un programa que describe el rendimiento en tiempo de ejecución de otro programa ofreciendo una variedad de estadísticas" - James Roskind, Python Docs

Por tanto, el perfilador de OpenObject es un módulo especial que registra la ejecución del Servidor de OpenObject, y muestra varios tipos de estadísticas. Permite analizar el rendimiento de OpenERP de manera sencilla. No es una herramienta para ser usada por si sóla, pero un buen compañero para herramientas como el analizador de logs de PostgreSQL pgFouine, o el perfilador de Python cProfile.

¿Qué nos da (a los programadores de OpenERP) que las herramientas genéricas no?

Bueno, trabaja al mismo nivel que los programadores de openobject, así que también habla nuestro lenguaje: En lugar de hablar sobre consultas SQL o llamadas a funciones de Python (conceptos que normalmente serán de grano demasiado fino para nosotros), habla sobre servicios OpenObject y métodos del ORM, no muestra nombres de tablas sino nombres de objetos, incluso entiende algunos de los parámetros de los métodos y los usa para perfilarlos mejor. Esta es la clase de estadísticas que se pueden obtener:

• Número de llamadas de servicio (desde un cliente OpenObject) y tiempo consumido.
• Métodos ORM invocados desde la capa de servicio (tiempos, orígenes de las llamadas...).
• Información de complegidad para los métodos de servicio y de ORM (los tiempos según el número de registros procesados).
• Uso de "browse records" en los métodos de servicio (e información de pérdidas).

Puedes encontrar el módulo en los extra addons de la versión 6.0 de OpenERP (quizá en el futuro lo porte también a la 5.0).

Por último, como adoro los ejemplos, aquí tienes una muestra de la salida del perfilador (generada tras algunas lecturas de menús):

/------------------------------------------------------------------------------\
|
| OpenObject Profiler Output
|
|------------------------------------------------------------------------------|
|------------------------------------------------------------------------------|
|
| Service method
| ir.ui.menu.read
|
| Calls   Time      Time per call
| 186     0.6144866 0.0033036
|
|     ORM methods called (by the service method):
|       ir.ui.menu.read
|       186     0.6038930 0.0032467
|          Called from (callers of the ORM method):
|            execute_cr@.../bin/osv/osv.py:167
|            186     0.6038930 0.0032467
|       ir.ui.menu.search
|       141     0.1454751 0.0010317
|          Called from (callers of the ORM method):
|            search@.../bin/addons/base/ir/ir_ui_menu.py:107
|            141     0.1454751 0.0010317
|       res.users.read
|       140     0.1129667 0.0008069
|          Called from (callers of the ORM method):
|            read@.../bin/addons/base/res/res_user.py:267
|            140     0.1129667 0.0008069
|
|     ORM sample call trace (for the service method):
|       0.001493930: ir.ui.menu.search - search@.../base/ir/ir_ui_menu.py:107
|       0.002168893: res.users.read - read@.../base/res/res_user.py:267
|       0.002876043: ir.ui.menu.read - execute_cr@...bin/osv/osv.py:167
|
|     Browse Records (used by the service method):
|       Created     Model
|       1314        ir.ui.menu
|
|     Complexity profile (records/items per service method call):
|       Complex.    Time/item   | Calls       Time        Time/call
|       1           0.003345962 | 70          0.234217405 0.003345962
|       2           0.001361489 | 1           0.002722978 0.002722978
|       3           0.001032924 | 100         0.309877395 0.003098773
|       8           0.000580956 | 9           0.041828870 0.004647652
|       9           0.000478519 | 6           0.025840044 0.004306674
|
|==============================================================================|
|
| Global Browse Records (used by all the service methods)
|
|       Created     Alive       Garbage     Model
|       1314        109         0           ir.ui.menu
|
|==============================================================================|
|
| Global ORM complexity log (records/items per orm method call)
|
|       Complex.    Time/item   | Calls       Time        Time/call
|       res.users.read
|       1           0.000814499 | 190         0.154754877 0.000814499
|       ir.ui.menu.read
|       1           0.003299624 | 70          0.230973720 0.003299624
|       2           0.001343965 | 1           0.002687931 0.002687931
|       3           0.001018521 | 148         0.452223539 0.003055564
|       5           0.000274610 | 2           0.002746105 0.001373052
|       8           0.000576370 | 9           0.041498661 0.004610962
|       9           0.000474298 | 6           0.025612115 0.004268685
|       21          0.001669777 | 3           0.105195999 0.035065333
|       38          0.000126301 | 3           0.014398336 0.004799445
|       77          0.000353303 | 3           0.081613063 0.027204354
|       78          0.000162627 | 3           0.038054943 0.012684981
|       ir.ui.menu.search
|       -           -           | 191         0.204602479 0.001071217
|
\------------------------------------------------------------------------------/