[6.1][account] slow large invoice validation because validate is called for every line

Bug #740361 reported by Raphaël Valyi - http://www.akretion.com
36
This bug affects 7 people
Affects Status Importance Assigned to Milestone
Odoo Addons (MOVED TO GITHUB)
Won't Fix
Low
Unassigned
6.1
New
Undecided
OpenERP Publisher's Warranty Team

Bug Description

edit account/account.py
and introduce some traceback print statement this way:

@@ -1378,6 +1385,9 @@
     # Validate a balanced move. If it is a centralised journal, create a move.
     #
     def validate(self, cr, uid, ids, context=None):
+# import traceback
+# traceback.print_stack()
+ print "validate", ids
         if context and ('__last_update' in context):
             del context['__last_update']

Now restart your server and try to validate an invoice with many lines, like 10 (cool you are not in production).
As you can see, that slow validate method is called for every invoice line, making the whole process very slow. Here in production it takes like 2 minutes to validate a 50 lines (with Brazilian taxes) invoice... Not very user friendly.

You'll see a similar traceback for every line:

  File "/opt/openerp-trunk/server/bin/osv/orm.py", line 181, in <lambda>
    return lambda *args, **argv: attr(self._cr, self._uid, [self._id], *args, **argv)
  File "/opt/openerp-trunk/addons/l10n_br_account/invoice.py", line 323, in action_move_create
    self.pool.get('account.move.line').write(cr, uid, [move_line.id for move_line in inv.move_id.line_id], {'ref': inv.internal_number})
  File "/opt/openerp-trunk/addons/account_payment_extension/account_move_line.py", line 168, in write
    return super(account_move_line, self).write(cr, uid, ids, vals, context, check, update_check)
  File "/opt/openerp-trunk/addons/account/account_move_line.py", line 1171, in write
    result = super(account_move_line, self).write(cr, uid, ids, vals, context)
  File "/opt/openerp-trunk/server/bin/osv/orm.py", line 3414, in write
    result += self._columns[field].set(cr, self, id, field, vals[field], user, context=rel_context) or []
  File "/opt/openerp-trunk/server/bin/osv/fields.py", line 830, in set
    self._fnct_inv(obj, cr, user, id, name, value, self._fnct_inv_arg, context)
  File "/opt/openerp-trunk/server/bin/osv/fields.py", line 881, in _fnct_write
    model.write(cr, uid, [t_id], {args[-1]: values}, context=context)
  File "/opt/openerp-trunk/addons/account/account.py", line 1240, in write
    self.validate(cr, uid, ids, context=context)
  File "/opt/openerp-trunk/addons/account/account.py", line 1389, in validate
    traceback.print_stack()
validate [543]

In "/opt/openerp-trunk/addons/account/account_move_line.py", line 1171, in write we still have a table of ids, so the hell loop is not born yet.
It will actually birth inside the ORM in "/opt/openerp-trunk/server/bin/osv/orm.py", line 3414, in write
where you'll iterate over each id.
I tend to think this is a first bad implementation, may be the real source of the bug. After this, we call validate for each account move line...

Still, it looks like you attempted to prevent this by strong a context c['novalidate'] = True flag.
a grep gives us:

~# grep -r novalidate /opt/openerp-trunk/addons/account/
/opt/openerp-trunk/addons/account/account.py: c['novalidate'] = True
/opt/openerp-trunk/addons/account/account.py: c['novalidate'] = True

But as you can see, it's a bit like marketing: totally useless. Sounds like a good intention but it has absolutely no effect at all, it's just no used.

So, I let you determine what is the proper fix, something in the ORM or some "novalidate" trickery before somebody remove the trick by mistake again to fox some side effect bug...

Hope this helps.

Tags: maintenance

Related branches

Revision history for this message
Borja López Soilán (NeoPolus) (borjals) wrote :

I can confirm this problem, we have experienced it on the Spanish localization for OpenERP 5.0 when undoing the fiscal year closing (the fiscal year closing wizard of the Spanish localization allows to undo the closing operations anytime).

On a normal production database, creating the fiscal year closing move (a big move, as it has a line per non-zeroed account) takes about 2 to 4 seconds, deleting the same move takes 20 to 40 seconds.

Revision history for this message
Amit Parik (amit-parik) wrote : Re: [6.0.1][account] slow large invoice validation because validate is called for every line

Hello,

I have tested your scenario with latest trunk at my end but I am not able to get any traceback.
So would you please provide the proper steps to reproduce it.

Thanks.

summary: - [6.0.1][account] dog slow large invoice validation because validate is
+ [6.0.1][account] slow large invoice validation because validate is
called for every line
Changed in openobject-addons:
status: New → Incomplete
Revision history for this message
Raphaël Valyi - http://www.akretion.com (rvalyi) wrote : Re: [Bug 740361] Re: [6.0.1][account] slow large invoice validation because validate is called for every line
Download full text (4.9 KiB)

Amit,

did you understand that you should apply my patch for the traceback to show
up? The problem is not the traceback, the problem is we loop over and over
the validate slow method for each invoice line while which makes invoice
validation times slower than it should be. The Traceback is just meant to
show you we are passing here over and over and from where so you can fix the
bug (possibly in the ORM).

On Thu, Mar 24, 2011 at 7:50 AM, Amit Parik (OpenERP) <email address hidden>wrote:

> Hello,
>
> I have tested your scenario with latest trunk at my end but I am not able
> to get any traceback.
> So would you please provide the proper steps to reproduce it.
>
> Thanks.
>
> ** Summary changed:
>
> - [6.0.1][account] dog slow large invoice validation because validate is
> called for every line
> + [6.0.1][account] slow large invoice validation because validate is called
> for every line
>
> ** Changed in: openobject-addons
> Status: New => Incomplete
>
> --
> You received this bug notification because you are a direct subscriber
> of the bug.
> https://bugs.launchpad.net/bugs/740361
>
> Title:
> [6.0.1][account] slow large invoice validation because validate is
> called for every line
>
> Status in OpenERP Modules (addons):
> Incomplete
>
> Bug description:
> edit account/account.py
> and introduce some traceback print statement this way:
>
> @@ -1378,6 +1385,9 @@
> # Validate a balanced move. If it is a centralised journal, create a
> move.
> #
> def validate(self, cr, uid, ids, context=None):
> +# import traceback
> +# traceback.print_stack()
> + print "validate", ids
> if context and ('__last_update' in context):
> del context['__last_update']
>
>
> Now restart your server and try to validate an invoice with many lines,
> like 10 (cool you are not in production).
> As you can see, that slow validate method is called for every invoice
> line, making the whole process very slow. Here in production it takes like 2
> minutes to validate a 50 lines (with Brazilian taxes) invoice... Not very
> user friendly.
>
> You'll see a similar traceback for every line:
>
> File "/opt/openerp-trunk/server/bin/osv/orm.py", line 181, in <lambda>
> return lambda *args, **argv: attr(self._cr, self._uid, [self._id],
> *args, **argv)
> File "/opt/openerp-trunk/addons/l10n_br_account/invoice.py", line 323,
> in action_move_create
> self.pool.get('account.move.line').write(cr, uid, [move_line.id for
> move_line in inv.move_id.line_id], {'ref': inv.internal_number})
> File
> "/opt/openerp-trunk/addons/account_payment_extension/account_move_line.py",
> line 168, in write
> return super(account_move_line, self).write(cr, uid, ids, vals,
> context, check, update_check)
> File "/opt/openerp-trunk/addons/account/account_move_line.py", line
> 1171, in write
> result = super(account_move_line, self).write(cr, uid, ids, vals,
> context)
> File "/opt/openerp-trunk/server/bin/osv/orm.py", line 3414, in write
> result += self._columns[field].set(cr, self, id, field, vals[field],
> user, context=rel_context) or []
> File "/opt/openerp-trunk/server/bin/osv/fie...

Read more...

Changed in openobject-addons:
status: Incomplete → New
Revision history for this message
Raphaël Valyi - http://www.akretion.com (rvalyi) wrote : Re: [6.0.1][account] slow large invoice validation because validate is called for every line

guys, any news on that one? Any chance it's confirmed or escalated to something important? I have an angry customer because of that one. Yes, we should sell OPW, but you know how it is, customer will only by one when he is satisfied enough, and for that in Brazil this still leaves us with a ton of work...

Revision history for this message
Raphaël Valyi - http://www.akretion.com (rvalyi) wrote :

Guys, to support my customers, I created a small ugly patch (attached). Basically I've seen that after the validate method is called once, we have an 'invoice' key in the context. I use that criterion to skip the validation for the next invoice lines.

This is very ugly and likely to be brittle if that invoice key is removed (but then it will just be as inefficient as today, not worse).

After applying this workaround, the move validation is called 'only' twice per invoice, that's still one useless call, but at least if you have an invoice with dozens of lines you will still save dozens of call to the exact same stupid validation.

So I call that an ugly work around that you can try at home if you are over 18, this doesn't seem like a proper long term fix, see my first comments about the problem if you want to elaborate a true solution to this bug.

Hope this helps. Please consider this is an important bug for 6.1. If you want to use OpenERP in companies larger than small SMB's you need to avoid this kind of bugs by design. Here I have a customer with only ~20 employees and he would almost dismiss from OpenERP without such a patch.

Revision history for this message
Cristian Salamea (ovnicraft) wrote :

Please update the milestone what is affecting this bug i want test it.

Regards,

Revision history for this message
Amit Parik (amit-parik) wrote : Re: [account] slow large invoice validation because validate is called for every line

Hello,

I have checked your issue and there is doesn't matter how many invoice lines are there.
But the def validate method call three time when we validate the invoice.

And this is not a bug it's improvement.
So I am set it as a "Triaged" and the related team will check the patch and they will decided.

Thanks for the understanding!

summary: - [6.0.1][account] slow large invoice validation because validate is
- called for every line
+ [account] slow large invoice validation because validate is called for
+ every line
Changed in openobject-addons:
assignee: nobody → OpenERP R&D Addons Team 3 (openerp-dev-addons3)
importance: Undecided → Low
status: New → Triaged
Revision history for this message
Raphaël Valyi - http://www.akretion.com (rvalyi) wrote : Re: [Bug 740361] Re: [account] slow large invoice validation because validate is called for every line
Download full text (5.1 KiB)

Guys, can anyone confirm what Amit said?
In my tests, the validate method is called as many times as I have invoice
lines, which is very very problematic here. Customer with 50 lines need to
wait 2 minutes to have their invoice validated, call it an improvement...
I'm not sure this will encourage my customer o buy an OPW :-(

On Fri, May 6, 2011 at 9:39 AM, Amit Parik (OpenERP) <email address hidden>wrote:

> Hello,
>
> I have checked your issue and there is doesn't matter how many invoice
> lines are there.
> But the def validate method call three time when we validate the invoice.
>
> And this is not a bug it's improvement.
> So I am set it as a "Triaged" and the related team will check the patch and
> they will decided.
>
> Thanks for the understanding!
>
> ** Summary changed:
>
> - [6.0.1][account] slow large invoice validation because validate is called
> for every line
> + [account] slow large invoice validation because validate is called for
> every line
>
> ** Changed in: openobject-addons
> Importance: Undecided => Low
>
> ** Changed in: openobject-addons
> Status: New => Triaged
>
> ** Changed in: openobject-addons
> Assignee: (unassigned) => OpenERP R&D Addons Team 3
> (openerp-dev-addons3)
>
> --
> You received this bug notification because you are a member of OpenERP
> Drivers, which is subscribed to OpenERP Addons.
> https://bugs.launchpad.net/bugs/740361
>
> Title:
> [account] slow large invoice validation because validate is called for
> every line
>
> Status in OpenERP Modules (addons):
> Triaged
>
> Bug description:
> edit account/account.py
> and introduce some traceback print statement this way:
>
> @@ -1378,6 +1385,9 @@
> # Validate a balanced move. If it is a centralised journal, create a
> move.
> #
> def validate(self, cr, uid, ids, context=None):
> +# import traceback
> +# traceback.print_stack()
> + print "validate", ids
> if context and ('__last_update' in context):
> del context['__last_update']
>
>
> Now restart your server and try to validate an invoice with many lines,
> like 10 (cool you are not in production).
> As you can see, that slow validate method is called for every invoice
> line, making the whole process very slow. Here in production it takes like 2
> minutes to validate a 50 lines (with Brazilian taxes) invoice... Not very
> user friendly.
>
> You'll see a similar traceback for every line:
>
> File "/opt/openerp-trunk/server/bin/osv/orm.py", line 181, in <lambda>
> return lambda *args, **argv: attr(self._cr, self._uid, [self._id],
> *args, **argv)
> File "/opt/openerp-trunk/addons/l10n_br_account/invoice.py", line 323,
> in action_move_create
> self.pool.get('account.move.line').write(cr, uid, [move_line.id for
> move_line in inv.move_id.line_id], {'ref': inv.internal_number})
> File
> "/opt/openerp-trunk/addons/account_payment_extension/account_move_line.py",
> line 168, in write
> return super(account_move_line, self).write(cr, uid, ids, vals,
> context, check, update_check)
> File "/opt/openerp-trunk/addons/account/account_move_line.py", line
> 1171, in write
> result = super(account...

Read more...

Revision history for this message
Mustufa Rangwala (Open ERP) (mra-tinyerp) wrote : Re: [account] slow large invoice validation because validate is called for every line

Hello,

Tested in latest trunk addons.

I have created invoice with more then 10 invoice lines. And i can see validate method on account.move called only three times not as much as its number of invoice lines.

So i agree with Amit and this bug seems invalid for trunk.
Thanks all for the discussion and contributions.

If i am wrong you can reopen it.

Regards,
mra

Amit Parik (amit-parik)
Changed in openobject-addons:
assignee: OpenERP R&D Addons Team 3 (openerp-dev-addons3) → nobody
Revision history for this message
Amit Parik (amit-parik) wrote :

Hello,

I have also checked this issue with latest stable version which have the same behavior as well as trunk.

So according to comment #9 I am closing this issue.

Thanks for understanding!

Changed in openobject-addons:
status: Triaged → Invalid
Revision history for this message
Ray Carnes (rcarnes) wrote :

Can I re-open this please?

I am getting the same thing with 6.1.

I have an OPW customer who reported ONE HOUR to validate an invoice with just over 100 lines.

I put the print statement and can see validate is called on the same single ID over and over again. I stopped counting at two screens full and terminated the server because it was taking too long to validate.

Ray.

Changed in openobject-addons:
status: Invalid → New
Revision history for this message
Amit Parik (amit-parik) wrote :

Hello Ray,

As latest OpenERP7 is released and version 7 doesn't have this problem as well as trunk are also works fine.
This problem only exists on 6.1, So for this kind of stable versions issue doesn't consider as a bug.

So as per bug management policy, if you have support and maintenance contract with us then you can contact our OPW team at <email address hidden>. They will defiantly helps you!.

Thank you!

summary: - [account] slow large invoice validation because validate is called for
- every line
+ [6.1][account] slow large invoice validation because validate is called
+ for every line
Changed in openobject-addons:
status: New → Won't Fix
Revision history for this message
Vadim - Enapps LTD (vadim-enapps) wrote :

I just looked at v7 code for def validate(self, cr, uid, ids, context=None): and there are no changes there, so I am not sure how this couod be fixed in v7 if the function is a full copy of 6.1

tags: added: maintenance
Revision history for this message
gilbert (gi6bert) wrote :

I am using openERP 6.0.3, OpenERP application getting slow, when validating the invoice or opening any new form. It automatically openerp application get slow. When running it manual then it working fine. Again its goes slow. I have to know the root cause. Kindly help me this issues.

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.