By activating the profiler debugger, the two qweb options is added. The
qweb templates that need to be rendered are compiled into a new function
to add instructions for saving data.
`Add qweb directive context`
It's a sub-option of "Record sql" or "Record traces", add some context on
thread at current call stack level. This context stored by collector
beside stack and is used by Speedscope to add a level to the stack with
this qweb directive information.
```
directive=t-call='website.layout', xpath=/t/t
t_call_content
directive=t-foreach='5' t-as="'a', xpath=/t/t/div/div
directive=t-esc='website.search([])', xpath=/t/t/div/div/t
execute
```
`Record qweb`
Add profiling data used by ProfilingQwebView widget. In the `ir.profile`
form view, the widget display the duration and number of sql of every qweb
directives with the xml of templates. Every xml is recorded to be
consulted even if the user change the xml templates.
```xml
<t t-call="website.layout">
<div>
<div t-foreach="5" t-as="a">
<t t-esc="website.search([])"/> <!-- will display 5 separate requests -->
</div>
</div>
</t>
```
closesodoo/odoo#74712
Signed-off-by: Xavier Dollé (xdo) <xdo@odoo.com>
When using profiling on a fresh test database, it can be tedious to
access settings to enable the feature. This commit adds a wizard to help
enabling profiling without accessing the settings when trying to
activate profiling on a administrator session.
closesodoo/odoo#75967
Signed-off-by: Xavier Dollé (xdo) <xdo@odoo.com>
Entry count can be useful to estimate the size on disk of a profile
file.
The entry count would be quite expensive to compute and thus should be
stored. It is impossible to use a compute stored in this case, since
ir.profile shouldn't have any "business" logic upon insert.
closesodoo/odoo#71673
Signed-off-by: Raphael Collet (rco) <rco@openerp.com>
The profiling tools can be useful to profile a test of some execution
point but this is not convenient to identify a problem on a running
instance.
With this commit, an option available in the debug menu allows to add a
flag on the user sessions to enable profiling of all requests. Each
request will be saved in a different 'ir.profile' entry, but will be
grouped under the same session.
The profiling can be activated on all sessions, even for a public user,
but only if profiling is enabled on the database globally.
This commits also adds a speedscope view to visualize saved results in
the web client.
closesodoo/odoo#66590
Signed-off-by: Xavier Dollé (xdo) <xdo@odoo.com>
This commit adds tooling to profile performance and save execution by
saving stack traces and queries to a file/database in specific format.
----------
Collectors
----------
For now, three different profiling modes (aka Collectors) are available
even if a last once should be introduced by @Gorash to profile qweb
execution.
- SQLCollector (or 'sql'): Saves the current stack trace and the query
every time Cursor.execute() is called. Any query executed on the thread
will be collected, no matter the cursor.
- PeriodicCollector (or 'traces_async'): Saves the stack trace every
'interval' seconds using a parallel thread to profile the caller thread.
The python implementation was optimized to minimize impact on
performance while remaining portable and easy to enable/disable
inside a odoo execution. Higher the frequency (lower the interval),
more impactful the profiling will become on the execution and increase
memory usage. From last experiments, 1ms looks to be a good minimum for
short executions.
- SyncCollector (or 'traces_sync'): Saves the stack trace every function
call/return. This collector is obviously quite impactful on performance
and can quickly overload the memory for long executions, but this is
quite useful to understand the precise path followed by some short
executions. Any time related information will be almost irrelevant with this
collector.
A base Collector defining minimal collectors features can easily be
extended to create custom collectors if needed.
----------------
Profiler & Usage
----------------
Collectors are not supposed to be used by themselves, but should be
given to a Profiler. The Profiler will synchronize collectors starts and
stop, and manage saving them to a file of in a ir_profile in the
database.
Exemple of usage:
```
with Profiler():
do_stuff()
```
This simple example will use the default collectors (sql and
traces_async) and save them to the database. The database is defined
automatically from current_thread 'dbname' if available.
Example of usage:
```
with Profiler(collectors=['sql'], db=False, path=/home/user/logs/do_stuff_profile/{time}):
do_stuff()
```
This more complex example disable the default behavior consisting
to save to the database, gives a path where the profile will be saved
and specify to only use the 'sql' collector. Note that
collectors=[SQLCollector()] would have the same behavior since
Collectors can be either a Collector instance or a string describing the
desired collector. This allows to define custom params for the
collectors and use custom collectors if needed.
Note that it is always possible to get results after execution without
saving it since they are available on the profiler.
```
with Profiler(collectors=['sql'], db=False) as p:
do_stuff()
print(len([None for entry in p.collectors[0].entries if ...]))
```
Profiler will also save the stack below the profiler start point, and
collectors will only collect the part of the stack over this stack.
This is a good way to reduce collectors CPU and memory usage.
Collected entries will be saved as follows:
```
[{
'start': 2.0,
'context': {},
'stack': [
['path_to_file', lno, 'func_name', 'line_content'],
...
],
},
...
]
```
SQLCollector will add three additional keys on each entry:
- query (query without parameters)
- full_query (mogrified query with parameters)
- time (the 'exact' execution time of the query)
----------------
ExecutionContext
----------------
A last tool, ExecutionContext, allows to define some context on some block of code:
Example of usage:
```
def process_modules(modules)
for module in modules:
with ExecutionContext(module=module): # note the 'not linter frienldy but still convenient' 2 spaces indentation
do_stuff(module):
```
This context will automatically be added in the stack as a virtual frame between
process_modules and do_stuff in order to split do_stuff from one single frame to
one frame per module.
----------
Speedscope
----------
The saved data are in a simple json format easy to analyze, but can't be visualized in
speedscope as they are. A utility class `Speedscope` can be used to generate a format
readable by speedscope. The used format is actually the format defined by speedscope,
meaning that all features should be available using it.
The output format is evented, meaning that we need to transform a list of samples
(a list of stack) to a list of event (going in/out a frame).
This is the main task of the Speedscope, as well as combining samples from different
sources, to display SQLCollector and PeriodicCollector results mixed together.
When stored on an ir_profile, the default speedscope generation can easily be generated
with the speedscope computed field.
This class can be used as it is but will mainly be useful for the next commit.
Special thanks to @rco-odoo for the in depth review and @Gorash for support.
Gorash