Overall performance issue of BaseModel.fields_view_get - binary fields should not be prefetched

I did some investigations again, and it appears that the real cause is the browse of the `_inherits'ed` partner of the user.

The partner ID of the user lmaurer has the ID 649.

In openerp.osv.orm.BaseModel._read_flat, at line 3657, there is a simple query on the res_partner:

            for sub_ids in cr.split_for_in_conditions(ids):
                cr.execute(query, [tuple(sub_ids)] + rule_params)
                results = cr.dictfetchall()

The query being executed:

SELECT res_partner."ean13",res_partner."zip_id",res_partner."tz",res_partner."opt_out",res_partner."title",res_partner."parent_id",res_partner."last_reconciliation_date",res_partner."employee",res_partner."fax",res_partner."image_medium",res_partner."name",res_partner."debit_limit",res_partner."signup_token",res_partner."street",res_partner."bank_statement_label",res_partner."country_id",res_partner."notification_email_send",res_partner."supplier",res_partner."ref",res_partner."email",res_partner."street2",res_partner."signup_expiration",res_partner."zip",res_partner."comment",res_partner."color",res_partner."image",res_partner."city",res_partner."user_id",res_partner."type",res_partner."function",res_partner."phone",res_partner."customer",res_partner."image_small",res_partner."birthdate",res_partner."vat",res_partner."state_id",res_partner."website",res_partner."use_parent_address",res_partner. "signup_type",res_partner."date",res_partner."is_company",res_partner."vat_subjected",res_partner."section_id",res_partner."lang",res_partner."credit_limit",res_partner."mobile",res_partner.id FROM "res_partner" WHERE res_partner.id IN (649) ORDER BY name

And the time it takes to do the cr.execute:
cr.execute: 0:00:00.716974

I had to delve way too far in the server to find the cause of this issue, but I finally found the root cause.
The query took a lot of time to execute because a very big image was uploaded on the partner.

As the partner is inherits'ed by the user, each time OpenERP needed to do a browse on the current user, it took nearly 1 second to read the image from the database.

I removed the image and OpenERP is fast again.

The work around is simple.

However, that revealed an issue which I think is really important: the images should not be prefetched, they should be read from the database only if they are really necessary (display on the views, ...), because:
 - images are used in more and more objects (user, partner, products, ...)
 - we do browse on the records much more often than we need their image
 - this is a true but insidious performance killer, even if we limit the size of the images, each browse will take significantly more time, and this will be more noticeable on loops

Example, this simple loop:

    for partner in self.pool.get('res.partner').browse(cr, uid, ids, context=context):
        print partner.name

Would take a lot of time to read all the images from the database just to print the name.

Hello,

I absolutely agree with Guewen: binary fields should absolutely not be
pre-fetched! Only lazily when explicitly required. BTW, this is something I
implemented in OOOR a couple of month ago: avoid to pre-fetch images at
least on the RPC layer and just doing that kind of doubled the perceived
performance in general. But in any case, even in the ORM itself,
pre-fetching binaries should totally be avoided!

On Fri, May 10, 2013 at 10:49 AM, Guewen Baconnier @ Camptocamp <
<email address hidden>> wrote:

> I did some investigations again, and it appears that the real cause is
> the browse of the `_inherits'ed` partner of the user.
>
> The partner ID of the user lmaurer has the ID 649.
>
> In openerp.osv.orm.BaseModel._read_flat, at line 3657, there is a simple
> query on the res_partner:
>
> for sub_ids in cr.split_for_in_conditions(ids):
> cr.execute(query, [tuple(sub_ids)] + rule_params)
> results = cr.dictfetchall()
>
> The query being executed:
>
> SELECT
>
> res_partner."ean13",res_partner."zip_id",res_partner."tz",res_partner."opt_out",res_partner."title",res_partner."parent_id",res_partner."last_reconciliation_date",res_partner."employee",res_partner."fax",res_partner."image_medium",res_partner."name",res_partner."debit_limit",res_partner."signup_token",res_partner."street",res_partner."bank_statement_label",res_partner."country_id",res_partner."notification_email_send",res_partner."supplier",res_partner."ref",res_partner."email",res_partner."street2",res_partner."signup_expiration",res_partner."zip",res_partner."comment",res_partner."color",res_partner."image",res_partner."city",res_partner."user_id",res_partner."type",res_partner."function",res_partner."phone",res_partner."customer",res_partner."image_small",res_partner."birthdate",res_partner."vat",res_partner."state_id",res_partner."website",res_partner."use_parent_address",res_partner.
>
> "signup_type",res_partner."date",res_partner."is_company",res_partner."vat_subjected",res_partner."section_id",res_partner."lang",res_partner."credit_limit",res_partner."mobile",
> res_partner.id
> FROM "res_partner" WHERE res_partner.id IN (649) ORDER BY name
>
> And the time it takes to do the cr.execute:
> cr.execute: 0:00:00.716974
>
>
> I had to delve way too far in the server to find the cause of this issue,
> but I finally found the root cause.
> The query took a lot of time to execute because a very big image was
> uploaded on the partner.
>
> As the partner is inherits'ed by the user, each time OpenERP needed to
> do a browse on the current user, it took nearly 1 second to read the
> image from the database.
>
> I removed the image and OpenERP is fast again.
>
> The work around is simple.
>
> However, that revealed an issue which I think is really important: the
> images should not be prefetched, they should be read from the database only
> if they are really necessary (display on the views, ...), because:
> - images are used in more and more objects (user, partner, products, ...)
> - we do browse on the records much more often than we need their image
> - this is a true but insidious performance killer, even if we limit the
> size ...

Hi Guewen, Raphael,

Thanks a lot for your detail analysis. I agree with your point, browsing on the name would also fetch the image and will take significant time. In my test I uploaded around 2 MB images on around 50 partner and it took 8 seconds to display them.
I think for stable version we should avoid uploading images with very big size. We could have a mechanism to restrict pre-fetching
images and that can be done in the trunk version only. IMHO we should discuss and think over it for trunk and for stable larger images should be avoided.

Let me know your suggestions.
Regards,
Rifakat

Hi Rikafat,

Thanks for your confirmation and acknowledgement.

I'm very conscious that it is by no means a trivial fix and it could be hard / risky to change in stable version.

However, while the loading of 50 partners with a 2mb image taking 8 seconds is bad, I think we can live with it because the chances to have such a configuration seems low, at worse we'll have a mitigation of small and big images.

Mine concern here is more on the upload of a big image on a user account. If I upload a 2mb image on my own user, each time I click on a menu, it will take ~8 seconds to load. This is discouraging and makes the usage of OpenERP almost unusable for this user.

The thing is that, you know it as well as I do, we cannot prevent users to upload big images.

All that being said, I think that 2 actions could be done in the stable version while doing a mechanism to restrict pre-fetching in trunk:

 - Replace the `browse` by a `read` as I did in `res_company._company_default_get()` -> this method is called several times each time we display a view and this single change drastically reduces the loading time when a big image is used (even if a small image is used, it will improve the performance here). Note that other `browse` of the user may have the same issue but this is the one I spotted and come the more often.

 - Prevent the upload of a image too large or resize it if it is too large.

In my opinion, this is an acceptable mitigation of the issue for the stable version while a better one is done in trunk.

What do you think?
Thanks

Guewen

Hi Guewen,

>- Replace the `browse` by a `read` as I did in `res_company._company_default_get()`
I agree this method is used widely in all the modules and specifically setting default value for the company_id into _defaults.
However, I think the actual problem lies in the return value of this method(return user.comapny_id.id) as per your first
comment in the bug report and we can simply use read() instead of this return value.

There is not need to replace `browse` by `read` as this should not impact on the performance. Doing user.company_id.id calls
`browse_record` and reads all the m2o field of company_id and that becomes company_id > partner_id > user_id and that should
be prevented. What do you think?

Doing `return user.company_id.id` actually reads value for these fields in class `browse_record` along with company_id,
['menu_id', 'alias_id', 'share', 'active', 'password', 'partner_id', 'id', 'login_date', 'company_id', 'signature', 'login', 'action_id', 'comment', 'ean13', 'color', 'image', 'alias_model_id', 'use_parent_address', 'street', 'birthdate', 'signup_type', 'display_name', 'supplier', 'city', 'user_id', 'opt_out', 'title', 'alias_force_thread_id', 'alias_defaults', 'country_id', 'company_id', 'notification_email_send', 'last_reconciliation_date', 'parent_id', 'employee', 'is_company', 'alias_user_id', 'type', 'email', 'vat', 'function', 'lang', 'fax', 'zip', 'street2', 'phone', 'credit_limit', 'ref', 'date', 'active', 'tz', 'signup_expiration', 'customer', 'image_medium', 'name', 'mobile', 'debit_limit', 'image_small', 'website', 'signup_token', 'alias_name', 'state_id']

Please share your suggestion on this and let me know if I have missed anything.
Warm regards,
Rifakat

Hi,

My feeling is that as soon as we read any field (not only company_id) of the browse_record, it reads all the other fields along and then read the large image. However, the call to browse() itself is not time consuming. But I don't have actually the structure to test that again.

If my feeling is right and if we:
 - replace the return value by a read of the company_id instead of the browse (like my proposition and your patch)
 - leave the browse given to the rules

->
In most cases, we won't have a penalty of performance.
If we create a rule, as soon as an attribute of the user is read, it will read the image and get a penalty. However, I don't think we have any choice because we absolutely need to leave the browse here as it can be used in the rules (this case can only be resolved by removing the images from the pre-fetching, so for trunk only). I don't know whether these rules are widely used or not (my impression is not).

Summarizing: I think that replacing the return value by a read() will improve most of the cases, while the lasting cases (when using rules) will be resolved only in trunk when the images will no longer be pre-fetched in the browse().

Thanks
Guewen

Guewen,
Fixed this in below branch authored to you,
lp:~openerp-dev/openobject-server/7.0-opw-592482-rha
r4998, <email address hidden>

Thanks a lot for reporting this bug,
Rifakat

The implementation of the prefetching system of browse_record was indeed incorrect. The _prefetch attribute on osv.fields classes is meant to exclude columns during the prefetching phase, but it was only used to determine whether to trigger the prefetching phase.

This has been fixed in the following revisions:

- server 7.0: 5014 rev-id: <email address hidden>
- server 6.1: 4355 rev-id: <email address hidden>
- server 6.0: 3664 rev-id: <email address hidden>

(automatic forward-port to trunk will follow)

The fix is safe for all stable versions because it only affects the internals of browse_record, but not its API. It may cause an extra SQL query when a binary field is accessed explicitly after other fields, but will save time in all the cases where it is not.
It may theoretically break custom code that was strongly coupled with the internals of browse_records, and accessing the browse cache directly while assuming binary values would be present in it due to the bug. It is believed that the overall performance improvement of the fix definitely outweighs possibly breaking these flawed use cases.

Thanks for reporting and tracking the root cause for your symptoms :-)

Whoopee! Excellent news!

Thanks Olivier