Openbravo Issue Tracking System - Openbravo ERP
View Issue Details
0038205Openbravo ERPI. Performancepublic2018-03-22 18:132018-05-09 19:30
gorkaion 
collazoandy4 
urgentmajoralways
closedfixed 
5
 
3.0PR18Q3 
dmiguelez
Core
No
0038205: Cost Adjustment Process very slow
A Cost Adjustment on an environment with 16k transactions and adjusting 11.5k takes almost 10h to complete.

After a review in YourKit there are 3 areas of improvement.
1. Method that inserts m_transaction_cost records.
2. Logic to calculate new LineNo of Cost Adjustment Line.
3. Inserts in Cost Adjustment Line. (already reported to platform in a separate issue 0038197 )

On an environment with around 16k transactions using manufacturing.
Execute a Cost Adjustment on one of the oldest transactions of a raw material.
This adjustment will also impact all items produced with that raw material resulting in a cost adjustment including many m_transactions, and much more adjustment lines.
Attached a patch extracted from a customer test instance with a tentative fix for issues 1st and 2nd, and other changes to improve performance. This patch does changes in following core files reducing the time to 2.5h:

AverageCostAdjustment:
- Logger using wrong class.
- Remove not needed save() from updated objects.
CostAdjustmentProcess:
- Remove not needed save() from updated objects.
- generateTransactionCosts():
-- Do the flush() only once at the end.
-- Evict the trx object on each iteration as it is not modified. Or instead of loading the full trx change to a query retrieving only the required properties.
-- Even better change the method to use a unique insert statement.
CostAdjustementUtils:
- getNewLineNo() method consumes too much time when many lines are added on a single adjustment.
-- Change order and get first by a get max(line) -> when there is no index on the order column it performs better.
-- Add a new insertCostAdjustmentLine() with a lineNo parameter so it is not required to call the getNewLineNo() method.
CostingAlgorithmAdjustmentImp:
- Add new field nextLineNo to store last LineNo used to use new API in CostAdjustmentUtils and avoid the query to get the max lineno.


With the provided patch the flush() still takes almost 1/3 of the total time. Other changes that could be considered are:

in any class involved:
- Review if there are more flush() and save() that can be removed.
- Review if it is possible to do a query to get a single property instead of the full BaseOBObject to reduce memory usage and fasten the flushes when the BaseOBObject is not expected to be updated.

AverageCostAdjustment:
- 2 flushes required when updating m_costing to avoid the trigger that disables the ability to modify a permanent costing.
-- Consider a massive update of the m_costing to set the flag to false and another one at the end to set it back to true to avoid 2 flushes on each m_costing update. Or disable the trigger when the CostAdjustmentProcess is running.
No tags attached.
related to defect 0038197 acknowledged Triage Platform Base TreeTablesEventHandler performance issue on processes with lots of inserts 
related to defect 0038206 closed collazoandy4 Cost Adjustment Process generates too much lines 
diff cost-adjustment-performance.diff (8,528) 2018-03-22 18:13
https://issues.openbravo.com/file_download.php?file_id=11669&type=bug
Issue History
2018-03-22 18:13gorkaionNew Issue
2018-03-22 18:13gorkaionAssigned To => Triage Finance
2018-03-22 18:13gorkaionFile Added: cost-adjustment-performance.diff
2018-03-22 18:13gorkaionModules => Core
2018-03-22 18:13gorkaionResolution time => 1523484000
2018-03-22 18:13gorkaionTriggers an Emergency Pack => No
2018-03-22 18:14ngarciaIssue Monitored: ngarcia
2018-03-22 18:14gorkaionRelationship addedrelated to 0038197
2018-03-22 18:29gorkaionIssue cloned0038206
2018-03-22 18:31gorkaionRelationship addedrelated to 0038206
2018-04-09 19:36aferrazAssigned ToTriage Finance => collazoandy4
2018-04-10 23:19collazoandy4Statusnew => scheduled
2018-04-17 08:48dmiguelezStatusscheduled => feedback
2018-04-20 13:09gorkaionStatusfeedback => scheduled
2018-05-02 18:13collazoandy4Note Added: 0104211
2018-05-03 17:42dmiguelezNote Added: 0104240
2018-05-04 09:27hgbotCheckin
2018-05-04 09:27hgbotNote Added: 0104271
2018-05-04 09:27hgbotStatusscheduled => resolved
2018-05-04 09:27hgbotResolutionopen => fixed
2018-05-04 09:27hgbotFixed in SCM revision => http://code.openbravo.com/erp/devel/pi/rev/ce7759e1ac82ca358fb57295a3c8db53830b0664 [^]
2018-05-04 09:27hgbotCheckin
2018-05-04 09:27hgbotNote Added: 0104272
2018-05-04 09:27hgbotCheckin
2018-05-04 09:27hgbotNote Added: 0104274
2018-05-04 09:27hgbotCheckin
2018-05-04 09:27hgbotNote Added: 0104275
2018-05-04 09:28dmiguelezReview Assigned To => dmiguelez
2018-05-04 09:28dmiguelezNote Added: 0104276
2018-05-04 09:28dmiguelezStatusresolved => closed
2018-05-04 09:28dmiguelezFixed in Version => 3.0PR18Q3
2018-05-09 19:29hudsonbotCheckin
2018-05-09 19:29hudsonbotNote Added: 0104428
2018-05-09 19:29hudsonbotCheckin
2018-05-09 19:29hudsonbotNote Added: 0104429
2018-05-09 19:29hudsonbotCheckin
2018-05-09 19:29hudsonbotNote Added: 0104431
2018-05-09 19:30hudsonbotCheckin
2018-05-09 19:30hudsonbotNote Added: 0104432

Notes
(0104211)
collazoandy4   
2018-05-02 18:13   
On an enviroment with 13 559 transactions made and adjustment of one transaction for a BOM product, the adjustment process took 14.38h and create a cost adjustment with 264 760 lines.
  With the fix for this issue applied on this enviroment the adjustment process only took 4.03h with a cost adjustment with the same lines (264 760)
(0104240)
dmiguelez   
2018-05-03 17:42   
After checking the execution with YourKit we have seen that:
- 56% of the time is taken ot insert the Cost Adjustment Lines. It takes that much time because there are many lines. There is little room for improvement here as of now
- 22% of the time is taken by AverageCostAdjustment.getTrxAdjustmentLines. This query is very fast (average of 1 ms), but is called many times. It could be a candidate to check for improvements in the future.
(0104271)
hgbot   
2018-05-04 09:27   
Repository: erp/devel/pi
Changeset: ce7759e1ac82ca358fb57295a3c8db53830b0664
Author: Armaignac <collazoandy4 <at> gmail.com>
Date: Thu Apr 12 10:29:51 2018 -0400
URL: http://code.openbravo.com/erp/devel/pi/rev/ce7759e1ac82ca358fb57295a3c8db53830b0664 [^]

Fixes issue 38205: Cost Adjustment Process very slow

A Cost Adjustment on an environment with 16k transactions and adjusting 11.5k
takes almost 10h to complete.

This patch does changes in following core files reducing the time to 2.5h:

AverageCostAdjustment:
- Logger using wrong class.
- Remove not needed save() from updated objects.
CostAdjustmentProcess:
- Remove not needed save() from updated objects.
  generateTransactionCosts():
-- Do the flush() only once at the end.
-- Evict the trx object on each iteration as it is not modified. Or instead of loading the full trx change to a query retrieving only the required properties.
-- Even better change the method to use a unique insert statement.

CostAdjustementUtils:
- getNewLineNo() method consumes too much time when many lines are added on a single adjustment.
-- Change order and get first by a get max(line) -> when there is no index on the order column it performs better.
-- Add a new insertCostAdjustmentLine() with a lineNo parameter so it is not required to call the getNewLineNo() method.

CostingAlgorithmAdjustmentImp:
- Add new field nextLineNo to store last LineNo used to use new API in CostAdjustmentUtils and avoid the query to get the max lineno.

---
M src/org/openbravo/costing/AverageCostAdjustment.java
M src/org/openbravo/costing/CostAdjustmentProcess.java
M src/org/openbravo/costing/CostAdjustmentUtils.java
M src/org/openbravo/costing/CostingAlgorithmAdjustmentImp.java
---
(0104272)
hgbot   
2018-05-04 09:27   
Repository: erp/devel/pi
Changeset: 0236ca5a68642fc136c1bcc732cba5e27cfbd4e5
Author: Armaignac <collazoandy4 <at> gmail.com>
Date: Thu Apr 12 11:27:33 2018 -0400
URL: http://code.openbravo.com/erp/devel/pi/rev/0236ca5a68642fc136c1bcc732cba5e27cfbd4e5 [^]

Related to issue 38205: Cost Adjustment Process very slow

A Cost Adjustment on an environment with 16k transactions and adjusting 11.5k
takes almost 10h to complete.

A refactor was made in order to improve the performance in the Cost Adjustment process
 * Removed unnecessary flush
 * Changed ScrollableResults to query
 * Code refactor

---
M src/org/openbravo/costing/AverageCostAdjustment.java
M src/org/openbravo/costing/CostAdjustmentProcess.java
M src/org/openbravo/costing/CostingAlgorithmAdjustmentImp.java
---
(0104274)
hgbot   
2018-05-04 09:27   
Repository: erp/devel/pi
Changeset: ac58569c1c06cf1550ffbbef7d4825a8a56411e0
Author: David Miguelez <david.miguelez <at> openbravo.com>
Date: Fri May 04 09:09:56 2018 +0200
URL: http://code.openbravo.com/erp/devel/pi/rev/ac58569c1c06cf1550ffbbef7d4825a8a56411e0 [^]

Related to Issue 38205, 38206. Code Review changes

* Extracted query into different method
* Use proper API for tests assertions
* Added missing brackets in if-else clauses

---
M src-test/src/org/openbravo/test/costing/TestCostingNoSourceAdjustments.java
M src-test/src/org/openbravo/test/costing/utils/TestCostingUtils.java
M src/org/openbravo/costing/CostAdjustmentUtils.java
---
(0104275)
hgbot   
2018-05-04 09:27   
Repository: erp/devel/pi
Changeset: e298e83db30127eca656898155b48617bdfa89d8
Author: David Miguelez <david.miguelez <at> openbravo.com>
Date: Fri May 04 09:13:06 2018 +0200
URL: http://code.openbravo.com/erp/devel/pi/rev/e298e83db30127eca656898155b48617bdfa89d8 [^]

Related to Issue 38205, 38206. Code Review changes

* Removed new variable and methods in tests API

---
M src-test/src/org/openbravo/test/costing/assertclass/CostAdjustmentAssert.java
---
(0104276)
dmiguelez   
2018-05-04 09:28   
Code Review + Testing Ok
(0104428)
hudsonbot   
2018-05-09 19:29   
A changeset related to this issue has been promoted main and to the
Central Repository, after passing a series of tests.

Promotion changeset: https://code.openbravo.com/erp/devel/main/rev/2be7d3efe606 [^]
Maturity status: Test
(0104429)
hudsonbot   
2018-05-09 19:29   
A changeset related to this issue has been promoted main and to the
Central Repository, after passing a series of tests.

Promotion changeset: https://code.openbravo.com/erp/devel/main/rev/2be7d3efe606 [^]
Maturity status: Test
(0104431)
hudsonbot   
2018-05-09 19:29   
A changeset related to this issue has been promoted main and to the
Central Repository, after passing a series of tests.

Promotion changeset: https://code.openbravo.com/erp/devel/main/rev/2be7d3efe606 [^]
Maturity status: Test
(0104432)
hudsonbot   
2018-05-09 19:30   
A changeset related to this issue has been promoted main and to the
Central Repository, after passing a series of tests.

Promotion changeset: https://code.openbravo.com/erp/devel/main/rev/2be7d3efe606 [^]
Maturity status: Test