Comment 6 for bug 1177965

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 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.
>
> --
> You received this bug notification because you are a member of OpenERP
> Drivers, which is subscribed to OpenERP Server.
> https://bugs.launchpad.net/bugs/1177965
>
> Title:
> Overall performance issue of BaseModel.fields_view_get
>
> Status in OpenERP Server:
> New
>
> Bug description:
> This bug is expressed by a general slowdown of the web client through
> all the
> application. Display any view may take several seconds.
>
> It does not happen on all the users. Some are afflicted, some are not.
> More
> weirdly, this happens in our production database, but not on the
> replication I
> did on my machine.
>
> According to my analysis, I guess that it happens only when
> report_webkit is
> installed (however a similar issue could probably happen without)
>
> Example of the issue:
>
> - I connect with lmaurer
> - I click on Sales > Customers
> - It takes 8 seconds to display the list
>
> See the attached screenshot.
>
> Most of the times is spent on the fields_view_get of the tree view (I
> attached
> the request and the response). fields_view_get is called 2 times (is it
> normal
> BTW?) and each times it takes ~3.10 seconds to achieve.
>
> I dived deep in the code to find out what actually happens.
> I will try to summarize that below.
>
> Finding from where comes the slowness:
> ======================================
>
> -> BaseModel.fields_view_get()
> Most of the time is spent when it builds the toolbar, precisely at the
> line
> 2274 when it gets the print actions:
>
> resprint = ir_values_obj.get(cr, user, 'action',
> 'client_print_multi', [(self._name, False)], False,
> context)
>
> -> ir_values.get()
> Forward to ir_values.get_actions()
>
> -> ir_values.get_actions()
> Most of the time is spent when it reads the action at line 404:
>
> action_def = self.pool.get(action_model).read(cr, uid, int(id),
> fields, context)
>
> Here, `fields` contains all the columns of the action, excepted a list of
> fields which are blacklisted in
> openerp.addons.base.ir.ir_values.EXCLUDED_FIELDS
>
> It appears that the field `webkit_header` is in the list of the fields
> to read,
> but is not filtered out. This is a fields.property and it takes nearly
> 1.5
> seconds to compute. (as we have few actions, it is multiplied by the
> number of
> actions).
>
> An easy fix would be to add this field in the `EXCLUDED_FIELDS` list,
> but that's only a part of the solution, it would mask the root cause.
>
> The real problem is the read on ir_actions_report_xml.webkit_header
> which takes
> 1.5 seconds to achieve.
>
>
> Finding why the read of the fields.property is so slow:
> =======================================================
>
> Note that I was now able to know that the slowness does not comes from
> the
> client nor from fields_view_get (directly). Just by doing a
> ir_actions_report_xml.read() (for instance with `erppeek`) on the field
> `webkit_header`, I'm able to reproduce the issue, it takes between 1.5
> to 3
> seconds to compute.
>
> So I dived more deeply in the call stack
>
> -> fields.property._fnct_read()
> Most of the time here is spent when it gets the property, at line 1447:
>
> value = prop.get(cr, uid, prop_name, obj._name,
> res_id=obj_reference, context=context)
>
> -> ir_property.get()
> Most of the time is spent when it builds the search domain at line 159:
>
> domain = self._get_domain(cr, uid, name, model, context=context)
>
> -> ir_property._get_domain()
> Most of the time is spent when it gets the default company at line 185:
>
> cid = company._company_default_get(cr, uid, model, res[0],
> context=context)
>
> -> res_company._company_default_get()
>
> Here is an extract of this method:
>
> user = self.pool.get('res.users').browse(cr, SUPERUSER_ID, uid,
> context=context)
> for rule in proxy.browse(cr, uid, ids, context):
> if eval(rule.expression, {'context': context, 'user': user}):
> return rule.company_dest_id.id
> return user.company_id.id
>
> It appears that the returned value is the thing which consumes all that
> time.
> It takes ~0.7s, but seems to be called a couple of time.
> I replaced it by a read like that:
>
> user_obj = self.pool.get('res.users')
> user = user_obj.browse(cr, SUPERUSER_ID, uid, context=context)
> for rule in proxy.browse(cr, uid, ids, context):
> if eval(rule.expression, {'context': context, 'user': user}):
> return rule.company_dest_id.id
> return user_obj.read(cr, SUPERUSER_ID,
> uid,
> ['company_id'],
> context=context)['company_id'][0]
>
> And it was fast again.
>
> I did not dived more deeply to see why the browse of the company take as
> much
> time because I was running out of time. Could it be related to function
> fields
> or _inherits? I cannot explain neither why it happens on a server and
> not on
> another. I cannot figure out neither why for some users that's really
> slower
> than others (the same fields_view_get on my user takes ~500 ms, lmaurer
> 3s,
> some users 80ms).
>
> I didn't check if the search_read which lasts 1.17 seconds is normal,
> but it
> seems less shocking as it returns all the data of the records, including
> the
> function fields.
>
> Conclusion
> ==========
>
> * I think that `webkit_header` should be added to
> openerp.addons.base.ir.ir_values.EXCLUDED_FIELDS
> when the report_webkit addon is installed because it is probably not
> necessary to compute it, however
> that's not a fix for the root cause.
>
> * I think that we should replace the browse by a read in
> res_company._company_default_get() because
> it takes way too much time. Alternatively this method could be cached
> but I could be a problem
> if the context is necessary.
>
> * I think that further analysis should be done on the browse because it
> seems not normal to me that
> user.company_id.id takes 0.7s.
> b
>
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/openobject-server/+bug/1177965/+subscriptions
>