[6.0] Useless read on product.product make openerp very slow

[Sébastien BEAU - http://www.akretion.com]

Hi
Two of my customers (who have maintenance contract) have some very bad performance when they open the product product menu.
Actually they are using the V5 version but as I plan to migrate them, I start to work on the V6 performance. After some inspection I understand why opening the menu is so slow.
Indeed when you try to read only one field (for example the price_list) by doing : product.price_list, the ORM launch a read request on all product fields (as my customers use Magento they can have more than 100 fields!!)

You can reproduce this bug easily and without the module magentoerpconnect, you just have to install the module product

Open the file server/bin/osv/orm.py line 2930 and add

    def read(self, cr, user, ids, fields=None, context=None, load='_classic_read'):
+ print 'fields', fields
+ if fields and 'produce_delay' in fields and len(fields)>2:
+ print jkjkjk

Restart the server and open the menu sale=>product=>product

The server will raise an error
And here is the stack trace

fields ['ean13', 'price_extra', 'default_code', 'name_template', 'active', 'variants', 'product_tmpl_id', 'price_margin', 'warranty', 'supply_method', 'uos_id', 'list_price', 'weight', 'standard_price', 'mes_type', 'uom_id', 'description_purchase', 'cost_method', 'uos_coeff', 'purchase_ok', 'product_manager', 'company_id', 'state', 'loc_rack', 'uom_po_id', 'type', 'loc_case', 'description', 'weight_net', 'volume', 'procure_method', 'loc_row', 'sale_ok', 'rental', 'sale_delay', 'name', 'description_sale', 'categ_id', 'produce_delay']
[2011-03-08 10:25:07,903][product_bug] ERROR:web-services:Uncaught exception
Traceback (most recent call last):
  File "/home/sebastien/DEV/openerp/6.0/server/bin/osv/osv.py", line 122, in wrapper
    return f(self, dbname, *args, **kwargs)
  File "/home/sebastien/DEV/openerp/6.0/server/bin/osv/osv.py", line 176, in execute
    res = self.execute_cr(cr, uid, obj, method, *args, **kw)
  File "/home/sebastien/DEV/openerp/6.0/server/bin/osv/osv.py", line 167, in execute_cr
    return getattr(object, method)(cr, uid, *args, **kw)
  File "/home/sebastien/DEV/openerp/6.0/server/bin/osv/orm.py", line 2944, in read
    result = self._read_flat(cr, user, select, fields, context, load)
  File "/home/sebastien/DEV/openerp/6.0/server/bin/osv/orm.py", line 3064, in _read_flat
    res2 = self._columns[f].get(cr, self, ids, f, user, context=context, values=res)
  File "/home/sebastien/DEV/openerp/6.0/server/bin/osv/fields.py", line 793, in get
    res = self._fnct(obj, cr, user, ids, name, self._arg, context)
  File "/home/sebastien/DEV/openerp/6.0/addons/product/product.py", line 419, in _product_lst_price
    res[product.id] = product.list_price
  File "/home/sebastien/DEV/openerp/6.0/server/bin/osv/orm.py", line 292, in __getattr__
    return self[name]
  File "/home/sebastien/DEV/openerp/6.0/server/bin/osv/orm.py", line 205, in __getitem__
    field_values = self._table.read(self._cr, self._uid, ids, field_names, context=self._context, load="_classic_write")
  File "/home/sebastien/DEV/openerp/6.0/server/bin/osv/orm.py", line 2932, in read
    print jkjkjk
NameError: global name 'jkjkjk' is not defined

As you can see when we try to read only one field 'list_price' the ORM will try to read this fields => 'ean13', 'price_extra', 'default_code', 'name_template', 'active', 'variants', 'product_tmpl_id', 'price_margin', 'warranty', 'supply_method', 'uos_id', 'list_price', 'weight', 'standard_price', 'mes_type', 'uom_id', 'description_purchase', 'cost_method', 'uos_coeff', 'purchase_ok', 'product_manager', 'company_id', 'state', 'loc_rack', 'uom_po_id', 'type', 'loc_case', 'description', 'weight_net', 'volume', 'procure_method', 'loc_row', 'sale_ok', 'rental', 'sale_delay', 'name', 'description_sale', 'categ_id', 'produce_delay'

The problem is in the function def __getitem__(self, name): line 192 (in the same file).

if col._prefetch:
    # gen the list of "local" (ie not inherited) fields which are classic or many2one
    fields_to_fetch = filter(lambda x: x[1]._classic_write, self._table._columns.items())
    # gen the list of inherited fields
    inherits = map(lambda x: (x[0], x[1][2]), self._table._inherit_fields.items())
    # complete the field list with the inherited fields which are classic or many2one
    fields_to_fetch += filter(lambda x: x[1]._classic_write, inherits)
# otherwise we fetch only that field
else:
    fields_to_fetch = [(name, col)]

If you add some print you will see that the value of "name" is 'price_list' and the value of "col._prefetch" is 'True' and so all fields are added to the fields_to_fetch. Normally as we when to read only one field we have to execute the code "fields_to_fetch = [(name, col)]".

Best Regards

[Sharoon Thomas http://openlabs.co.in (sharoonthomas)]

I agree that this is a big mess indeed and slows down the system drastically.

In the case of magentoerpconnect this could be overcome by redoing the whole system in EAV [1]. Thats quite a bit of work though but could solve other bugs [2].

[1] http://en.wikipedia.org/wiki/Entity-attribute-value_model
[2] https://bugs.launchpad.net/magentoerpconnect/+bug/648667

[Raphaël Valyi - http://www.akretion.com (rvalyi)]

Hello guys,

just discussed with Sebastien: after what he says, they would be no reason to pre-fectch values in read as those aren't even put in suitable cache for later reuse with read. Sebastien I let you detail your experiments here.

@Sharoon, as for the Magentoerpconnect specific use case, I made a post here
https://lists.launchpad.net/openerp-expert-framework/msg00522.html
where I give my idea to improve the performance of those sparse attribute using a JSON data bag in postgresql. I would be curious what you think about it.

@Jay thank you for your reactivity with our customer with maintenance contracts, this is very much appreciated.

[Sébastien BEAU - http://www.akretion.com (sebastien.beau)]

I made some test and for each read done an sql request is done. So it's look like no cache is used, so it's better to read only the fields needed.

@Jay thanks also for your reactivity.

[Olivier Dony (Odoo) (odo-openerp)]

Sebastien, I don't think you guys are looking at the right place.

What you are describing is not a bug, but is simply the prefetching mechanism of browse(). When opening the product list, the product.product.read() is called with the list of fields the client needs to display. Some of these fields are function fields that are implemented using browse(). And when product.product is browsed, the prefetching mechanism of browse() will simply try to load all similar "basic" fields to the one being accessed, to avoid doing more queries than is necessary.
This will not necessarily be useful for all cases, but will also not make any noticeable difference in performance, because what matters is the number of database queries that are performed.
Simple example: for postgres, it is as fast to do:
       "SELECT id, a FROM TABLE WHERE id in (1,2,3)"
than to do:
       "SELECT id, a,b,c,d,e FROM TABLE WHERE id in (1,2,3)".
But by doing the latter, browse's prefetching avoids possible queries later, because after doing "record.a" you are likely to need "record.b.". And if you don't need it, no harm was done.

What matters is: browse will only load "basic" fields, fields that can be read from the database directly,and require no further computation. Look at the list of fields that browse() passes to read() and you will see they can all be read directly from the db. To convince yourself, you can simply try to measure the difference between doing product.product.read() on just one field, e.g ['name'], and doing the same on all basic fields of product, as listed in your description. And do the same for 1 or for 100 product, and notice the difference.

What I mean is, the behavior you see is not caching done by read(), but caching done by browse(), which is reusable as long as your browse_record or browse_list is in the scope. I don't think it can be related to your performance problem, or at least not directly.

Yes of course, turning off browse's prefetching will remove that behavior, but it won't magically give you noticeably more performance, unless something else is abusing this... and turning it off *will* cause extra queries in places where browse's prefetching was useful! So be careful when you look at this..

If there is a performance problem when opening the product list in your databases, you might want to investigate further to see what is actually taking time (function fields that are not correctly written or should be stored, etc.), without making early assumptions on what you think is happening. Like for any performance problem, you need to measure precisely to understand where the source(s) of the performances issues are.

I'm setting this bug as incomplete until we have more evidence to point out to the source(s) of the issue.

[Sébastien BEAU - http://www.akretion.com (sebastien.beau)]

Thank a lot for your explication Olivier. Now I understand more the prefetching mechanism of the browse.
I will make more test and I will give my feed back.
For the moment kept the bug as incomplete.
Thanks a lot again.

[Sébastien BEAU - http://www.akretion.com (sebastien.beau)]

This is now fix in trunk version.
You can try it, but you should use this version of the server (merged soon): https://code.launchpad.net/~akretion-team/openobject-server/sparse_field

[Sébastien BEAU - http://www.akretion.com (sebastien.beau)]

Sparse field are merge in the 6.1 server and use in MagentoERPconnect so I close this bug