Borja López Soilánhttp://www.kami.eshttps://twitter.com/NeoPolus

Perfilador OpenObjectAnalizando el rendimiento de OpenERP

IV Jornadas de OpenERP 2011. Cámara de Comercio de Lugo.

Perfilador

"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

Perfilador OpenObject

Es un módulo más de OpenERP● Actualmente disponible en los extra-addons de la

versión 6.0: https://code.launchpad.net/~openerp-commiter/openobject-addons/extra-6.0

Registra la ejecución del Servidor de OpenObject/OpenERPCada vez que el servidor atiende una petición actualiza un archivo de estadísticas (o imprime la información en la consola)

Estadísticas

Número de llamadas de servicio (desde un cliente OpenObject) y tiempo consumidoMétodos ORM invocados desde la capa de servicio (tiempos, orígenes de las llamadas...)Información de complejidad 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)

Ejemplo

/------------------------------------------------------------------------------\|| 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|\------------------------------------------------------------------------------/

Úsese con...

El perfilador no sustituye al uso de otras herramientas:

Perfiladores de Pythonhttp://docs.python.org/library/profile.htmlAnálisis de SQLhttp://pgfouine.projects.postgresql.org/Análisis de consultashttp://www.postgresql.org/docs/8.1/static/sql-explain.html