Hi there,
 
I am trying to briefly test the performance of the ORM queries with the database.
There is little data in my database, but I can still do whatever tests I want.
 
However, I encounter an inconsistency regarding the first results of these tests...
 
Here is a simple random request directly executed on the postgres console:

# POSTGRES CMD #

$> EXPLAIN ANALYSE SELECT * FROM account_move_line WHERE amount_residual = 0 AND company_id = 1;

Seq Scan on account_move_line  (cost=0.00..136.25 rows=2877 width=385) (actual time=0.025..2.856 rows=2877 loops=1) 
Filter: ((amount_residual = '0'::numeric) AND (company_id = 1))
Rows Removed by Filter: 273
Planning time: 0.417 ms
Execution time: 3.253 ms
(5 rows)

As you can see, the request takes less than 4 milliseconds.

So, I decided to test this request directly in my code with the ORM:

# ORM # 
 
start_time = datetime.datetime.now() 
 
# Execute the request 100 times (to average) 
for i in range(100): 
    request = self.env['account.move.line'].search([('amount_residual', '=', 0), ('company_id', '=', 1)]) 
 
end_time = datetime.datetime.now() 
 
# Difference
delta = end_time - start_time 
# Average 
execution_time = delta.total_seconds() * 1000 / 100
 
print("Time ORM: " + str(execution_time) + " ms (" + str(len(request)) + ")")

Here is the result:

Time ORM: 4.57849 ms (2878 items)

Ok, great, not so far from our first request on the postgres console.
 
After that, I decided to test directly with the cursor, with always the same random request:

# CR # 
 
start_time = datetime.datetime.now() 
 
# Execute the request 100 times (to average) 
for i in range(100): 
    self.env.cr.execute("SELECT * FROM account_move_line WHERE amount_residual = 0 AND company_id = 1") 
#request = self.env.cr.fetchall() <= no fetchall for the moment 
 
end_time = datetime.datetime.now() 
 
# Calculate the difference between the two times 
delta = end_time - start_time 
# Calculate the average 
execution_time = delta.total_seconds() * 1000 / 100
 
print("Time CR: " + str(execution_time) + " ms") 

And the result is :

Time CR: 17.0679 ms 

Here is the point!

The cursor is supposed to be much faster than the ORM, not the other way around, right?
So, do you think I am performing this test the right way? Do you have any suggestions, ideas or information that explains this result?
 
I know the latest versions of Odoo improve performance, but I am still and need to do these tests on version 9.0.
 
Thank you in advance for your answers.